feat_: add pre login log (#6285)

* feat_: add pre login log

* chore_: add comments for switchToPreLoginLog

api/geth_backend.go

@@ -493,8 +493,12 @@ func (b *GethStatusBackend) ensureWalletDBOpened(account multiaccounts.Account,
 	return nil
 }
 
-func (b *GethStatusBackend) setupLogSettings() error {
-	logSettings := b.config.LogSettings()
+func (b *GethStatusBackend) SetupLogSettings() error {
+	// sync pre_login.log
+	if err := logutils.ZapLogger().Sync(); err != nil {
+		return errors.Wrap(err, "failed to sync logger")
+	}
+	logSettings := b.config.DefaultLogSettings()
 	return logutils.OverrideRootLoggerWithConfig(logSettings)
 }
 
@@ -577,7 +581,12 @@ func (b *GethStatusBackend) LoginAccount(request *requests.Login) error {
 	if b.LocalPairingStateManager.IsPairing() {
 		return nil
 	}
-	return b.LoggedIn(request.KeyUID, err)
+	err = b.LoggedIn(request.KeyUID, err)
+	if err != nil {
+		return errors.Wrap(err, "failed to send LoggedIn signal")
+	}
+
+	return nil
 }
 
 // This is a workaround to make user be able to login again, the root cause is where the node config migration
@@ -754,11 +763,6 @@ func (b *GethStatusBackend) loginAccount(request *requests.Login) error {
 		overrideApiConfig(b.config, request.APIConfig)
 	}
 
-	err = b.setupLogSettings()
-	if err != nil {
-		return errors.Wrap(err, "failed to setup log settings")
-	}
-
 	accountsDB, err := accounts.NewDB(b.appDB)
 	if err != nil {
 		return errors.Wrap(err, "failed to create accounts db")
@@ -873,11 +877,6 @@ func (b *GethStatusBackend) startNodeWithAccount(acc multiaccounts.Account, pass
 		return err
 	}
 
-	err = b.setupLogSettings()
-	if err != nil {
-		return err
-	}
-
 	accountsDB, err := accounts.NewDB(b.appDB)
 	if err != nil {
 		return err
@@ -2681,6 +2680,10 @@ func (b *GethStatusBackend) Logout() error {
 		signal.SendNodeStopped()
 	}
 
+	if err = b.switchToPreLoginLog(); err != nil {
+		return err
+	}
+
 	// re-initialize the node, at some point we should better manage the lifecycle
 	b.initialize()
 
@@ -2692,6 +2695,18 @@ func (b *GethStatusBackend) Logout() error {
 	return nil
 }
 
+// switchToPreLoginLog switches to global pre-login logging settings.
+// This log is profile-independent and should be enabled by default,
+// including in release builds, to help diagnose login issues.
+// related issue: https://github.com/status-im/status-mobile/issues/21501
+func (b *GethStatusBackend) switchToPreLoginLog() error {
+	err := logutils.ZapLogger().Sync()
+	if err != nil {
+		return err
+	}
+	return logutils.OverrideRootLoggerWithConfig(b.config.PreLoginLogSettings())
+}
+
 // cleanupServices stops parts of services that doesn't managed by a node and removes injected data from services.
 func (b *GethStatusBackend) cleanupServices() error {
 	b.selectedAccountKeyID = ""

cmd/utils/utils.go

@@ -15,7 +15,7 @@ func SetupLogging(logLevel *string, logWithoutColors *bool, config *params.NodeC
 		config.LogLevel = *logLevel
 	}
 
-	logSettings := config.LogSettings()
+	logSettings := config.DefaultLogSettings()
 	logSettings.Colorized = !(*logWithoutColors) && terminal.IsTerminal(int(os.Stdin.Fd()))
 	if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil {
 		stdlog.Fatalf("Error initializing logger: %v", err)

logutils/override.go

@@ -1,6 +1,7 @@
 package logutils
 
 import (
+	"bufio"
 	"io"
 	"os"
 
@@ -58,7 +59,10 @@ func overrideCoreWithConfig(filteringCore *namespaceFilteringCore, settings LogS
 			Compress:   settings.CompressRotated,
 		}))
 	} else {
-		core.UpdateSyncer(zapcore.Lock(os.Stderr))
+		// run TestLoginWithKey will get error: sync /dev/stdout: bad file descriptor
+		// use bufio.NewWriter to wrap os.Stderr to fix it
+		writer := bufio.NewWriter(os.Stderr)
+		core.UpdateSyncer(zapcore.Lock(zapcore.AddSync(writer)))
 	}
 
 	// FIXME: remove go-libp2p logging altogether

mobile/status.go

@@ -151,10 +151,14 @@ func initializeLogging(request *requests.InitializeApplication) error {
 		request.LogDir = request.DataDir
 	}
 
+	if request.LogLevel == "" {
+		request.LogLevel = params.DefaultPreLoginLogLevel
+	}
+
 	logSettings := logutils.LogSettings{
-		Enabled: request.LogEnabled,
+		Enabled: true, // always enable pre-login logging
 		Level:   request.LogLevel,
-		File:    path.Join(request.LogDir, api.DefaultLogFile),
+		File:    path.Join(request.LogDir, params.DefaultPreLoginLogFile),
 	}
 
 	err := os.MkdirAll(request.LogDir, 0700)
@@ -543,7 +547,7 @@ func createAccountAndLogin(requestJSON string) string {
 			return statusBackend.LoggedIn("", err)
 		}
 		logutils.ZapLogger().Debug("started a node, and created account")
-		return nil
+		return statusBackend.SetupLogSettings()
 	})
 	return makeJSONResponse(nil)
 }
@@ -580,7 +584,7 @@ func loginAccount(requestJSON string) string {
 			return err
 		}
 		logutils.ZapLogger().Debug("loginAccount started node")
-		return nil
+		return statusBackend.SetupLogSettings()
 	})
 	return makeJSONResponse(nil)
 }
@@ -615,7 +619,7 @@ func restoreAccountAndLogin(requestJSON string) string {
 			return statusBackend.LoggedIn("", err)
 		}
 		logutils.ZapLogger().Debug("started a node, and restored account")
-		return nil
+		return statusBackend.SetupLogSettings()
 	})
 
 	return makeJSONResponse(nil)
@@ -658,7 +662,7 @@ func SaveAccountAndLogin(accountData, password, settingsJSON, configJSON, subacc
 			return err
 		}
 		logutils.ZapLogger().Debug("started a node, and saved account", zap.String("key-uid", account.KeyUID))
-		return nil
+		return statusBackend.SetupLogSettings()
 	})
 	return makeJSONResponse(nil)
 }

params/config.go

@@ -1157,7 +1157,7 @@ func LesTopic(netid int) string {
 	}
 }
 
-func (c *NodeConfig) LogSettings() logutils.LogSettings {
+func (c *NodeConfig) DefaultLogSettings() logutils.LogSettings {
 	return logutils.LogSettings{
 		Enabled:         c.LogEnabled,
 		Level:           c.LogLevel,
@@ -1168,3 +1168,19 @@ func (c *NodeConfig) LogSettings() logutils.LogSettings {
 		CompressRotated: c.LogCompressRotated,
 	}
 }
+
+func (c *NodeConfig) PreLoginLogSettings() logutils.LogSettings {
+	logFile := filepath.Join(c.LogDir, DefaultPreLoginLogFile)
+	if c.LogLevel == "" {
+		c.LogLevel = DefaultPreLoginLogLevel
+	}
+	return logutils.LogSettings{
+		Enabled:         true,
+		Level:           c.LogLevel,
+		Namespaces:      c.LogNamespaces,
+		File:            logFile,
+		MaxSize:         c.LogMaxSize,
+		MaxBackups:      c.LogMaxBackups,
+		CompressRotated: c.LogCompressRotated,
+	}
+}

params/defaults.go

@@ -83,6 +83,9 @@ const (
 
 	// IpfsGatewayURL is the Gateway URL to use for IPFS
 	IpfsGatewayURL = "https://ipfs.status.im/"
+
+	DefaultPreLoginLogFile  = "pre_login.log"
+	DefaultPreLoginLogLevel = "ERROR"
 )
 
 var (

tests-functional/tests/test_init_status_app.py

@@ -67,14 +67,15 @@ def test_check_logs(log_enabled: bool, api_logging_enabled: bool):
             "dataDir": str(data_dir),
             "logDir": str(logs_dir),
             "logEnabled": log_enabled,
+            "logLevel": "INFO",
             "apiLoggingEnabled": api_logging_enabled,
         },
     )
 
-    local_geth_log = backend.extract_data(os.path.join(logs_dir, "geth.log"))
+    pre_login_log = backend.extract_data(os.path.join(logs_dir, "pre_login.log"))
     local_api_log = backend.extract_data(os.path.join(logs_dir, "api.log"))
 
-    assert_file_first_line(path=local_geth_log, pattern="logging initialised", expected=log_enabled)
+    assert_file_first_line(path=pre_login_log, pattern="logging initialised", expected=True)
 
     assert_file_first_line(
         path=local_api_log,