diff --git a/api/defaults.go b/api/defaults.go index eff89e401..4982bda98 100644 --- a/api/defaults.go +++ b/api/defaults.go @@ -27,11 +27,13 @@ const ( shardsTestClusterID = 16 walletAccountDefaultName = "Account 1" - DefaultKeystoreRelativePath = "keystore" - DefaultKeycardPairingDataFile = "/ethereum/mainnet_rpc/keycard/pairings.json" - DefaultDataDir = "/ethereum/mainnet_rpc" - DefaultNodeName = "StatusIM" - DefaultLogFile = "geth.log" + DefaultKeystoreRelativePath = "keystore" + DefaultKeycardPairingDataFile = "/ethereum/mainnet_rpc/keycard/pairings.json" + DefaultDataDir = "/ethereum/mainnet_rpc" + DefaultNodeName = "StatusIM" + DefaultLogFile = "geth.log" + DefaultAPILogFile = "api.log" + DefaultLogLevel = "ERROR" DefaultMaxPeers = 20 DefaultMaxPendingPeers = 20 diff --git a/api/geth_backend.go b/api/geth_backend.go index 2b1151757..b64055a8c 100644 --- a/api/geth_backend.go +++ b/api/geth_backend.go @@ -494,7 +494,6 @@ func (b *GethStatusBackend) ensureWalletDBOpened(account multiaccounts.Account, func (b *GethStatusBackend) setupLogSettings() error { logSettings := logutils.LogSettings{ Enabled: b.config.LogEnabled, - MobileSystem: b.config.LogMobileSystem, Level: b.config.LogLevel, File: b.config.LogFile, MaxSize: b.config.LogMaxSize, diff --git a/appdatabase/migrations/sql/1732570426_.up.sql b/appdatabase/migrations/sql/1732570426_.up.sql new file mode 100644 index 000000000..20e43caa4 --- /dev/null +++ b/appdatabase/migrations/sql/1732570426_.up.sql @@ -0,0 +1 @@ +ALTER TABLE log_config DROP COLUMN mobile_system; \ No newline at end of file diff --git a/appdatabase/node_config_test.go b/appdatabase/node_config_test.go index 4841651e5..c21c31066 100644 --- a/appdatabase/node_config_test.go +++ b/appdatabase/node_config_test.go @@ -159,7 +159,6 @@ func randomNodeConfig() *params.NodeConfig { IPCEnabled: randomBool(), IPCFile: randomString(), LogEnabled: randomBool(), - LogMobileSystem: randomBool(), LogDir: randomString(), LogFile: randomString(), LogLevel: randomString(), diff --git a/cmd/ping-community/main.go b/cmd/ping-community/main.go index 0ced6b2aa..74f58ab02 100644 --- a/cmd/ping-community/main.go +++ b/cmd/ping-community/main.go @@ -238,7 +238,6 @@ func setupLogging(config *params.NodeConfig) { logSettings := logutils.LogSettings{ Enabled: config.LogEnabled, - MobileSystem: config.LogMobileSystem, Level: config.LogLevel, File: config.LogFile, MaxSize: config.LogMaxSize, diff --git a/cmd/populate-db/main.go b/cmd/populate-db/main.go index 593fccadf..103833a12 100644 --- a/cmd/populate-db/main.go +++ b/cmd/populate-db/main.go @@ -282,7 +282,6 @@ func setupLogging(config *params.NodeConfig) { logSettings := logutils.LogSettings{ Enabled: config.LogEnabled, - MobileSystem: config.LogMobileSystem, Level: config.LogLevel, File: config.LogFile, MaxSize: config.LogMaxSize, diff --git a/cmd/status-backend/main.go b/cmd/status-backend/main.go index 900ba7cad..18af96a2b 100644 --- a/cmd/status-backend/main.go +++ b/cmd/status-backend/main.go @@ -22,10 +22,9 @@ var ( func init() { logSettings := logutils.LogSettings{ - Enabled: true, - MobileSystem: false, - Level: "INFO", - Colorized: terminal.IsTerminal(int(os.Stdin.Fd())), + Enabled: true, + Level: "INFO", + Colorized: terminal.IsTerminal(int(os.Stdin.Fd())), } if err := logutils.OverrideRootLoggerWithConfig(logSettings); err != nil { stdlog.Fatalf("failed to initialize log: %v", err) diff --git a/cmd/status-cli/util.go b/cmd/status-cli/util.go index 7b38447e1..e9bfe75a2 100644 --- a/cmd/status-cli/util.go +++ b/cmd/status-cli/util.go @@ -25,7 +25,6 @@ func setupLogger(file string) *zap.Logger { logFile := fmt.Sprintf("%s.log", strings.ToLower(file)) logSettings := logutils.LogSettings{ Enabled: true, - MobileSystem: false, Level: "DEBUG", File: logFile, MaxSize: 100, diff --git a/cmd/statusd/main.go b/cmd/statusd/main.go index aa1c61692..e50bcd5a1 100644 --- a/cmd/statusd/main.go +++ b/cmd/statusd/main.go @@ -396,7 +396,6 @@ func setupLogging(config *params.NodeConfig) { logSettings := logutils.LogSettings{ Enabled: config.LogEnabled, - MobileSystem: config.LogMobileSystem, Level: config.LogLevel, File: config.LogFile, MaxSize: config.LogMaxSize, diff --git a/logutils/override.go b/logutils/override.go index 65e68c16f..afb9b8cfc 100644 --- a/logutils/override.go +++ b/logutils/override.go @@ -11,7 +11,6 @@ import ( type LogSettings struct { Enabled bool `json:"Enabled"` - MobileSystem bool `json:"MobileSystem"` Level string `json:"Level"` File string `json:"File"` MaxSize int `json:"MaxSize"` @@ -39,11 +38,6 @@ func overrideCoreWithConfig(core *Core, settings LogSettings) error { } core.SetLevel(level) - if settings.MobileSystem { - core.UpdateSyncer(zapcore.Lock(os.Stdout)) - return nil - } - if settings.File != "" { if settings.MaxBackups == 0 { // Setting MaxBackups to 0 causes all log files to be kept. Even setting MaxAge to > 0 doesn't fix it diff --git a/logutils/override_test.go b/logutils/override_test.go index f81c121a2..37decf5d1 100644 --- a/logutils/override_test.go +++ b/logutils/override_test.go @@ -41,8 +41,7 @@ func TestOverrideCoreWithConfig(t *testing.T) { { name: "mobile system logging", settings: LogSettings{ - Enabled: true, - MobileSystem: true, + Enabled: true, }, expectError: false, }, diff --git a/mobile/callog/status_request_log.go b/mobile/callog/status_request_log.go index 781b7049c..00a3619c6 100644 --- a/mobile/callog/status_request_log.go +++ b/mobile/callog/status_request_log.go @@ -63,21 +63,9 @@ func getShortFunctionName(fn any) string { // 4. If request logging is enabled, logs method name, parameters, response, and execution duration // 5. Removes sensitive information before logging func Call(logger, requestLogger *zap.Logger, fn any, params ...any) any { - defer func() { - if r := recover(); r != nil { - logger.Error("panic found in call", zap.Any("error", r), zap.Stack("stacktrace")) - sentry.RecoverError(r) - panic(r) - } - }() - - var startTime time.Time - - requestLoggingEnabled := requestLogger != nil - if requestLoggingEnabled { - startTime = time.Now() - } + defer Recover(logger) + startTime := requestStartTime(requestLogger != nil) fnValue := reflect.ValueOf(fn) fnType := fnValue.Type() if fnType.Kind() != reflect.Func { @@ -97,18 +85,9 @@ func Call(logger, requestLogger *zap.Logger, fn any, params ...any) any { resp = results[0].Interface() } - if requestLoggingEnabled { - duration := time.Since(startTime) + if requestLogger != nil { methodName := getShortFunctionName(fn) - paramsString := removeSensitiveInfo(fmt.Sprintf("%+v", params)) - respString := removeSensitiveInfo(fmt.Sprintf("%+v", resp)) - - requestLogger.Debug("call", - zap.String("method", methodName), - zap.String("params", paramsString), - zap.String("resp", respString), - zap.Duration("duration", duration), - ) + Log(requestLogger, methodName, params, resp, startTime) } return resp @@ -129,3 +108,38 @@ func removeSensitiveInfo(jsonStr string) string { return fmt.Sprintf(`%s:"***"`, parts[1]) }) } + +func requestStartTime(enabled bool) time.Time { + if !enabled { + return time.Time{} + } + return time.Now() +} + +func Recover(logger *zap.Logger) { + err := recover() + if err == nil { + return + } + + logger.Error("panic found in call", + zap.Any("error", err), + zap.Stack("stacktrace")) + + sentry.RecoverError(err) + + panic(err) +} + +func Log(logger *zap.Logger, method string, params any, resp any, startTime time.Time) { + if logger == nil { + return + } + duration := time.Since(startTime) + logger.Debug("call", + zap.String("method", method), + zap.String("params", removeSensitiveInfo(fmt.Sprintf("%+v", params))), + zap.String("resp", removeSensitiveInfo(fmt.Sprintf("%+v", resp))), + zap.Duration("duration", duration), + ) +} diff --git a/mobile/status.go b/mobile/status.go index ab91cfae3..fdda8f72a 100644 --- a/mobile/status.go +++ b/mobile/status.go @@ -49,6 +49,9 @@ import ( "github.com/status-im/status-go/services/wallet/wallettypes" "github.com/status-im/status-go/signal" + "path" + "time" + "github.com/status-im/status-go/mobile/callog" ) @@ -66,7 +69,21 @@ type InitializeApplicationResponse struct { } func InitializeApplication(requestJSON string) string { - return callWithResponse(initializeApplication, requestJSON) + // NOTE: InitializeApplication is logs the call on its own rather than using `callWithResponse`, + // because the API logging is enabled during this exact call. + defer callog.Recover(logutils.ZapLogger()) + + startTime := time.Now() + response := initializeApplication(requestJSON) + callog.Log( + requestlog.GetRequestLogger(), + "InitializeApplication", + requestJSON, + response, + startTime, + ) + + return response } func initializeApplication(requestJSON string) string { @@ -80,38 +97,69 @@ func initializeApplication(requestJSON string) string { return makeJSONResponse(err) } + // Initialize logs + if request.LogDir == "" { + request.LogDir = request.DataDir + } + logSettings := logutils.LogSettings{ + Enabled: request.LogEnabled, + Level: request.LogLevel, + File: path.Join(request.LogDir, api.DefaultLogFile), + } + if err = logutils.OverrideRootLoggerWithConfig(logSettings); err == nil { + logutils.ZapLogger().Info("logging initialised", + zap.Any("logSettings", logSettings), + zap.Bool("APILoggingEnabled", request.APILoggingEnabled), + ) + } else { + return makeJSONResponse(err) + } + + if request.APILoggingEnabled { + logRequestsFile := path.Join(request.LogDir, api.DefaultAPILogFile) + err = requestlog.ConfigureAndEnableRequestLogging(logRequestsFile) + if err != nil { + return makeJSONResponse(err) + } + } + // initialize metrics providers.MixpanelAppID = request.MixpanelAppID providers.MixpanelToken = request.MixpanelToken statusBackend.StatusNode().SetMediaServerEnableTLS(request.MediaServerEnableTLS) - statusBackend.UpdateRootDataDir(request.DataDir) + + // Read available accounts err = statusBackend.OpenAccounts() if err != nil { return makeJSONResponse(err) } + accs, err := statusBackend.GetAccounts() if err != nil { return makeJSONResponse(err) } - centralizedMetricsInfo, err := statusBackend.CentralizedMetricsInfo() + + // Read centralized metrics info + metricsInfo, err := statusBackend.CentralizedMetricsInfo() if err != nil { return makeJSONResponse(err) } // initialize sentry statusBackend.SetSentryDSN(request.SentryDSN) - if centralizedMetricsInfo.Enabled { + if metricsInfo.Enabled { err = statusBackend.EnablePanicReporting() if err != nil { return makeJSONResponse(err) } } + // Prepare response response := &InitializeApplicationResponse{ Accounts: accs, - CentralizedMetricsInfo: centralizedMetricsInfo, + CentralizedMetricsInfo: metricsInfo, } data, err := json.Marshal(response) if err != nil { @@ -2162,6 +2210,7 @@ type InitLoggingRequest struct { // InitLogging The InitLogging function should be called when the application starts. // This ensures that we can capture logs before the user login. Subsequent calls will update the logger settings. // Before this, we can only capture logs after user login since we will only configure the logging after the login process. +// Deprecated: Use InitializeApplication instead func InitLogging(logSettingsJSON string) string { var logSettings InitLoggingRequest var err error diff --git a/nodecfg/node_config.go b/nodecfg/node_config.go index 9d5f1daa3..d3dd4441f 100644 --- a/nodecfg/node_config.go +++ b/nodecfg/node_config.go @@ -89,10 +89,10 @@ func insertHTTPConfig(tx *sql.Tx, c *params.NodeConfig) error { func insertLogConfig(tx *sql.Tx, c *params.NodeConfig) error { _, err := tx.Exec(` INSERT OR REPLACE INTO log_config ( - enabled, mobile_system, log_dir, log_level, max_backups, max_size, + enabled, log_dir, log_level, max_backups, max_size, file, compress_rotated, log_to_stderr, synthetic_id - ) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, 'id' )`, - c.LogEnabled, c.LogMobileSystem, c.LogDir, c.LogLevel, c.LogMaxBackups, c.LogMaxSize, + ) VALUES (?, ?, ?, ?, ?, ?, ?, ?, 'id' )`, + c.LogEnabled, c.LogDir, c.LogLevel, c.LogMaxBackups, c.LogMaxSize, c.LogFile, c.LogCompressRotated, c.LogToStderr, ) @@ -488,8 +488,8 @@ func loadNodeConfig(tx *sql.Tx) (*params.NodeConfig, error) { return nil, err } - err = tx.QueryRow("SELECT enabled, mobile_system, log_dir, log_level, file, max_backups, max_size, compress_rotated, log_to_stderr FROM log_config WHERE synthetic_id = 'id'").Scan( - &nodecfg.LogEnabled, &nodecfg.LogMobileSystem, &nodecfg.LogDir, &nodecfg.LogLevel, &nodecfg.LogFile, &nodecfg.LogMaxBackups, &nodecfg.LogMaxSize, &nodecfg.LogCompressRotated, &nodecfg.LogToStderr) + err = tx.QueryRow("SELECT enabled, log_dir, log_level, file, max_backups, max_size, compress_rotated, log_to_stderr FROM log_config WHERE synthetic_id = 'id'").Scan( + &nodecfg.LogEnabled, &nodecfg.LogDir, &nodecfg.LogLevel, &nodecfg.LogFile, &nodecfg.LogMaxBackups, &nodecfg.LogMaxSize, &nodecfg.LogCompressRotated, &nodecfg.LogToStderr) if err != nil && err != sql.ErrNoRows { return nil, err } diff --git a/params/config.go b/params/config.go index eeca6dacc..e1a40c47a 100644 --- a/params/config.go +++ b/params/config.go @@ -414,9 +414,6 @@ type NodeConfig struct { // LogEnabled enables the logger LogEnabled bool `json:"LogEnabled"` - // LogMobileSystem enables log redirection to android/ios system logger. - LogMobileSystem bool - // LogFile is a folder which contains LogFile LogDir string diff --git a/protocol/requests/initialize_application.go b/protocol/requests/initialize_application.go index 30f7a99ef..e2165db28 100644 --- a/protocol/requests/initialize_application.go +++ b/protocol/requests/initialize_application.go @@ -15,6 +15,14 @@ type InitializeApplication struct { // MediaServerEnableTLS is optional, if not provided, media server will use TLS by default MediaServerEnableTLS *bool `json:"mediaServerEnableTLS"` SentryDSN string `json:"sentryDSN"` + + // LogDir specifies the directory where logs are stored. + // If empty, logs are stored in the `DataDir`. + LogDir string `json:"logDir"` + + LogEnabled bool `json:"logEnabled"` + LogLevel string `json:"logLevel"` + APILoggingEnabled bool `json:"apiLoggingEnabled"` } func (i *InitializeApplication) Validate() error { diff --git a/tests-functional/tests/test_init_status_app.py b/tests-functional/tests/test_init_status_app.py index dac9884e4..9a2428168 100644 --- a/tests-functional/tests/test_init_status_app.py +++ b/tests-functional/tests/test_init_status_app.py @@ -1,5 +1,6 @@ from test_cases import StatusBackend import pytest +import os @pytest.mark.create_account @@ -22,7 +23,6 @@ class TestInitialiseApp: backend_client.restore_account_and_login() assert backend_client is not None - backend_client.verify_json_schema( backend_client.wait_for_signal("mediaserver.started"), "signal_mediaserver_started") backend_client.verify_json_schema( @@ -31,3 +31,52 @@ class TestInitialiseApp: backend_client.wait_for_signal("node.ready"), "signal_node_ready") backend_client.verify_json_schema( backend_client.wait_for_signal("node.login"), "signal_node_login") + + +@pytest.mark.rpc +@pytest.mark.skip("waiting for status-backend to be executed on the same host/container") +class TestInitializeLogging: + + @pytest.mark.init + def test_init_logging(self, tmp_path): + self.check_logs(tmp_path, log_enabled=True, api_logging_enabled=True) + + @pytest.mark.init + def test_no_logging(self, tmp_path): + self.check_logs(tmp_path, log_enabled=False, api_logging_enabled=False) + + + def assert_file_first_line(self, path, pattern: str, expected: bool): + assert os.path.exists(path) == expected + if not expected: + return + with open(path) as file: + line = file.readline() + line_found = line.find(pattern) >= 0 + assert line_found == expected + + def check_logs(self, path, log_enabled: bool, api_logging_enabled: bool): + data_dir = path / "data" + logs_dir = path / "logs" + + data_dir.mkdir() + logs_dir.mkdir() + + backend = StatusBackend() + backend.api_valid_request("InitializeApplication", { + "dataDir": str(data_dir), + "logDir": str(logs_dir), + "logEnabled": log_enabled, + "apiLoggingEnabled": api_logging_enabled, + }) + + self.assert_file_first_line( + logs_dir / "geth.log", + pattern="logging initialised", + expected=log_enabled) + + self.assert_file_first_line( + logs_dir / "api.log", + pattern='"method": "InitializeApplication"', + expected=api_logging_enabled) +