cmd: fix debug flag loading and add debug log to cache function

pkg/backtest/exchange.go

@@ -291,7 +291,7 @@ func (e Exchange) PlatformFeeCurrency() string {
 }
 
 func (e Exchange) QueryMarkets(ctx context.Context) (types.MarketMap, error) {
-	return bbgo.LoadExchangeMarketsWithCache(ctx, e.publicExchange)
+	return e.markets, nil
 }
 
 func (e Exchange) QueryDepositHistory(ctx context.Context, asset string, since, until time.Time) (allDeposits []types.Deposit, err error) {

pkg/bbgo/cache.go

@@ -11,6 +11,7 @@ import (
 
 	"github.com/c9s/bbgo/pkg/types"
 	"github.com/pkg/errors"
+	log "github.com/sirupsen/logrus"
 )
 
 type DataFetcher func() (interface{}, error)
@@ -24,6 +25,8 @@ func WithCache(key string, obj interface{}, fetcher DataFetcher) error {
 	cacheFile := path.Join(cacheDir, key+".json")
 
 	if _, err := os.Stat(cacheFile); os.IsNotExist(err) {
+		log.Debugf("cache %s not found, executing fetcher callback to get the data", cacheFile)
+
 		data, err := fetcher()
 		if err != nil {
 			return err
@@ -46,6 +49,7 @@ func WithCache(key string, obj interface{}, fetcher DataFetcher) error {
 		rv.Set(reflect.ValueOf(data))
 
 	} else {
+		log.Debugf("cache %s found", cacheFile)
 
 		data, err := ioutil.ReadFile(cacheFile)
 		if err != nil {

pkg/cmd/backtest.go

@@ -20,6 +20,7 @@ import (
 	"github.com/pkg/errors"
 	log "github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
+	"github.com/spf13/viper"
 )
 
 func init() {
@@ -47,6 +48,10 @@ var BacktestCmd = &cobra.Command{
 			return err
 		}
 
+		if viper.GetBool("debug") {
+			verboseCnt = 2
+		}
+
 		configFile, err := cmd.Flags().GetString("config")
 		if err != nil {
 			return err
@@ -103,6 +108,15 @@ var BacktestCmd = &cobra.Command{
 			return err
 		}
 
+		if verboseCnt == 2 {
+			log.SetLevel(log.DebugLevel)
+		} else if verboseCnt > 0 {
+			log.SetLevel(log.InfoLevel)
+		} else {
+			// default mode, disable strategy logging and order executor logging
+			log.SetLevel(log.ErrorLevel)
+		}
+
 		// if it's declared in the cmd , use the cmd one first
 		if exchangeNameStr == "" {
 			exchangeNameStr = userConfig.Backtest.Session
@@ -270,14 +284,7 @@ var BacktestCmd = &cobra.Command{
 		}
 
 		trader := bbgo.NewTrader(environ)
-
+		if verboseCnt == 0 {
-		if verboseCnt == 2 {
-			log.SetLevel(log.DebugLevel)
-		} else if verboseCnt > 0 {
-			log.SetLevel(log.InfoLevel)
-		} else {
-			// default mode, disable strategy logging and order executor logging
-			log.SetLevel(log.ErrorLevel)
 			trader.DisableLogging()
 		}
 

pkg/cmd/root.go

@@ -47,6 +47,11 @@ var RootCmd = &cobra.Command{
 			}
 		}
 
+		if viper.GetBool("debug") {
+			log.Infof("debug mode is enabled")
+			log.SetLevel(log.DebugLevel)
+		}
+
 		configFile, err := cmd.Flags().GetString("config")
 		if err != nil {
 			return errors.Wrapf(err, "failed to get the config flag")
@@ -81,7 +86,7 @@ var RootCmd = &cobra.Command{
 }
 
 func init() {
-	RootCmd.PersistentFlags().Bool("debug", false, "debug flag")
+	RootCmd.PersistentFlags().Bool("debug", false, "debug mode")
 	RootCmd.PersistentFlags().String("config", "bbgo.yaml", "config file")
 
 	RootCmd.PersistentFlags().Bool("no-dotenv", false, "disable built-in dotenv")
@@ -133,21 +138,10 @@ func init() {
 		return
 	}
 
-	if err := viper.BindPFlags(RootCmd.Flags()); err != nil {
+	log.SetFormatter(&prefixed.TextFormatter{})
-		log.WithError(err).Errorf("failed to bind local flags. please check the flag settings.")
-		return
-	}
 }
 
 func Execute() {
-
-	log.SetFormatter(&prefixed.TextFormatter{})
-
-	logger := log.StandardLogger()
-	if viper.GetBool("debug") {
-		logger.SetLevel(log.DebugLevel)
-	}
-
 	environment := os.Getenv("BBGO_ENV")
 	switch environment {
 	case "production", "prod":
@@ -161,6 +155,7 @@ func Execute() {
 		if err != nil {
 			log.Panic(err)
 		}
+		logger := log.StandardLogger()
 		logger.AddHook(
 			lfshook.NewHook(
 				lfshook.WriterMap{