From abcced1e50320a3733db342484970dc6e0f98961 Mon Sep 17 00:00:00 2001 From: Dmitrii Kozlov Date: Thu, 27 Jun 2024 12:58:02 +0300 Subject: [PATCH] structured logging --- api_test/app_settings_test.go | 5 +- api_test/invites_test.go | 12 +-- api_test/login_test.go | 10 +-- api_test/main_test.go | 13 +-- api_test/management_invite_test.go | 12 +-- api_test/misconfig_test/cors_test.go | 2 +- api_test/misconfig_test/main_test.go | 13 +-- api_test/mongo_app_test.go | 11 ++- api_test/mongo_user_integration_test.go | 11 ++- api_test/phone_login_test.go | 24 +++--- api_test/redis_session_test.go | 3 +- api_test/refresh_token_test.go | 12 +-- api_test/register_test.go | 6 +- api_test/reset_password_test.go | 6 +- config/config_test.go | 27 +++++-- config/config_watcher.go | 7 +- config/configurator.go | 76 +++++++++++------- config/storage.go | 58 +++++++------- config/storage_test.go | 3 +- impersonation/plugin/provider.go | 12 ++- jwt/pem.go | 6 +- jwt/rsa_test.go | 6 -- jwt/service/jwt_token_service.go | 20 ++++- jwt/token_test.go | 18 +++-- localization/localization.go | 6 +- logging/default.go | 43 ++++++++++ logging/fields.go | 12 +++ main.go | 87 +++++++++++++------- model/app_storage.go | 1 + model/server_settings.go | 9 ++- model/user_storage.go | 17 ++-- model/user_storage_test.go | 18 +++++ plugins/bolt-user-storage/main.go | 19 +++-- plugins/mongo-user-storage/main.go | 14 ++-- server-config.yaml | 6 +- server/server.go | 7 +- services/mail/mail.go | 28 +++++-- services/mail/mail_test.go | 3 +- services/mail/mock/mock.go | 28 +++++-- services/mail/ses/ses.go | 37 +++++---- services/sms/mock/mock.go | 16 ++-- services/sms/sms.go | 10 ++- services/sms/sms_test.go | 3 +- services/sms/twilio/twilio.go | 16 ++-- storage/app.go | 15 ++-- storage/boltdb/app.go | 20 +++-- storage/boltdb/app_test.go | 7 +- storage/boltdb/invite.go | 21 +++-- storage/boltdb/token.go | 18 +++-- storage/boltdb/token_blocklist.go | 17 ++-- storage/boltdb/user.go | 27 +++++-- storage/boltdb/verification_code.go | 18 +++-- storage/dynamodb/app.go | 41 +++++----- storage/dynamodb/db.go | 3 - storage/dynamodb/invite.go | 48 ++++++----- storage/dynamodb/management_keys.go | 19 +++-- storage/dynamodb/session.go | 30 ++++--- storage/dynamodb/token.go | 31 ++++--- storage/dynamodb/token_blocklist.go | 30 ++++--- storage/dynamodb/user.go | 89 ++++++++++++--------- storage/dynamodb/verification_code.go | 36 ++++++--- storage/fs/config_storage.go | 35 +++++--- storage/fs_watcher.go | 20 +++-- storage/fs_watcher_test.go | 15 +++- storage/invite.go | 11 ++- storage/keys.go | 8 +- storage/management_keys.go | 10 ++- storage/mem/app.go | 13 ++- storage/mongo/app.go | 22 +++-- storage/mongo/database_connection_tester.go | 12 ++- storage/mongo/invite.go | 10 ++- storage/mongo/management_keys.go | 30 ++++--- storage/mongo/mongo.go | 24 +++--- storage/mongo/token_blacklist.go | 10 ++- storage/mongo/token_refresh.go | 10 ++- storage/mongo/user.go | 31 ++++--- storage/mongo/verification_code.go | 10 ++- storage/plugin/user.go | 12 ++- storage/redis/session.go | 14 +++- storage/s3/fs_test.go | 2 +- storage/s3/fs_watcher_test.go | 7 +- storage/s3/key_storage_connection_tester.go | 3 +- storage/s3/keys.go | 44 +++++----- storage/s3/s3_config_storage.go | 27 ++++--- storage/s3/s3_storage_test.go | 21 ++--- storage/s3/s3_test.go | 2 +- storage/session.go | 10 ++- storage/token.go | 11 ++- storage/token_blacklist.go | 12 ++- storage/user.go | 11 ++- storage/verification_codes.go | 11 ++- user_payload_provider/plugin/provider.go | 13 ++- web/admin/apps.go | 16 ++-- web/admin/logout.go | 2 +- web/admin/middleware.go | 4 +- web/admin/router.go | 27 ++++--- web/admin/settings.go | 6 +- web/admin/test_connection.go | 6 +- web/admin/users.go | 7 +- web/api/2fa.go | 4 +- web/api/appsecret.go | 12 ++- web/api/dump_request.go | 20 ----- web/api/federated_login.go | 10 ++- web/api/federated_oidc_login.go | 33 +++----- web/api/federated_oidc_login_v2_test.go | 67 ---------------- web/api/hello.go | 6 +- web/api/impersonate_as.go | 9 ++- web/api/journal.go | 29 +++++++ web/api/login.go | 18 +++-- web/api/logout.go | 13 ++- web/api/phone_login.go | 3 + web/api/refresh_token.go | 13 ++- web/api/reset_password.go | 3 +- web/api/router.go | 25 +++--- web/api/utils.go | 2 +- web/management/reset_password.go | 8 +- web/management/router.go | 35 +++++--- web/management/routes.go | 3 - web/management/test.go | 3 +- web/middleware/middleware_app.go | 18 ++--- web/middleware/negroni_logger.go | 16 ---- web/router.go | 4 +- web/spa/router.go | 18 +++-- 123 files changed, 1323 insertions(+), 811 deletions(-) create mode 100644 logging/default.go create mode 100644 logging/fields.go create mode 100644 model/user_storage_test.go delete mode 100644 web/api/dump_request.go create mode 100644 web/api/journal.go delete mode 100644 web/middleware/negroni_logger.go diff --git a/api_test/app_settings_test.go b/api_test/app_settings_test.go index 25e6f1f0..b82a008e 100644 --- a/api_test/app_settings_test.go +++ b/api_test/app_settings_test.go @@ -21,7 +21,7 @@ func TestAppSettings(t *testing.T) { SetHeader("Digest", "SHA-256="+signature). SetHeader("Content-Type", "application/json"). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/app_settings_scheme.json"). @@ -45,7 +45,7 @@ func TestAppSettingsCORS(t *testing.T) { SetHeader("Digest", "SHA-256="+signature). SetHeader("Content-Type", "application/json"). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). AssertFunc(func(rsp *http.Response, r *http.Request) error { header = rsp.Header return nil @@ -53,7 +53,6 @@ func TestAppSettingsCORS(t *testing.T) { Status(204). Done() - fmt.Printf("Header %+v\n", header) assert.Contains(t, header.Get("Access-Control-Allow-Origin"), "http://localhost:3000") assert.Contains(t, header.Get("Access-Control-Allow-Methods"), "GET") } diff --git a/api_test/invites_test.go b/api_test/invites_test.go index d4411ac0..2effca59 100644 --- a/api_test/invites_test.go +++ b/api_test/invites_test.go @@ -35,7 +35,7 @@ func TestInvite(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). AssertFunc(validateJSON(func(data map[string]interface{}) error { @@ -47,7 +47,7 @@ func TestInvite(t *testing.T) { require.NotEmpty(t, at) data = fmt.Sprintf(` - { + { "email": "%s", "access_role": "%s", "callback_url": "%s", @@ -65,7 +65,7 @@ func TestInvite(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { link = data["link"].(string) return nil @@ -108,7 +108,7 @@ func TestInviteWithCustomLoginAppURL(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). AssertFunc(validateJSON(func(data map[string]interface{}) error { @@ -120,7 +120,7 @@ func TestInviteWithCustomLoginAppURL(t *testing.T) { require.NotEmpty(t, at) data = fmt.Sprintf(` - { + { "email": "%s", "access_role": "%s", "callback_url": "%s", @@ -138,7 +138,7 @@ func TestInviteWithCustomLoginAppURL(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { link = data["link"].(string) return nil diff --git a/api_test/login_test.go b/api_test/login_test.go index 312442b4..70d8d95f 100644 --- a/api_test/login_test.go +++ b/api_test/login_test.go @@ -34,7 +34,7 @@ func TestLogin(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). @@ -60,7 +60,7 @@ func TestLoginWithNoRefresh(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { g.Expect(data).To(MatchKeys(IgnoreExtras|IgnoreMissing, Keys{ "access_token": Not(BeZero()), @@ -81,7 +81,7 @@ func TestLoginWithWrongAppID(t *testing.T) { request.Post("/auth/login"). SetHeader("X-Identifo-ClientID", "wrong_app_ID"). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { g.Expect(data["error"]).To(MatchAllKeys(Keys{ "id": Equal(string(l.ErrorStorageAPPFindByIDError)), @@ -115,7 +115,7 @@ func TestLoginWithWrongSignature(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Status(400). AssertFunc(validateJSON(func(data map[string]interface{}) error { g.Expect(data["error"]).To(MatchAllKeys(Keys{ @@ -145,7 +145,7 @@ func TestLoginTokenClaims(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). AssertFunc(validateJSON(func(data map[string]interface{}) error { tokenStr = data["access_token"].(string) diff --git a/api_test/main_test.go b/api_test/main_test.go index b9152d69..76d7d2b9 100644 --- a/api_test/main_test.go +++ b/api_test/main_test.go @@ -18,6 +18,7 @@ import ( "github.com/caarlos0/env" "github.com/joho/godotenv" "github.com/madappgang/identifo/v2/config" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/services/mail/mock" "gopkg.in/h2non/baloo.v3" @@ -91,7 +92,7 @@ func runServer() (model.Server, *http.Server) { settings, _ = model.ConfigStorageSettingsFromString("file://../test/artifacts/api/config-mongo.yaml") } - configStorage, err := config.InitConfigurationStorage(settings) + configStorage, err := config.InitConfigurationStorage(logging.DefaultLogger, settings) if err != nil { log.Fatalf("Unable to load config with error: %v", err) } @@ -143,10 +144,12 @@ func stopServer(server *http.Server) { // Helper functions // DumpResponse -func dumpResponse(res *http.Response, req *http.Request) error { - data, err := httputil.DumpResponse(res, true) - fmt.Printf("Response: %s \n", string(data)) - return err +func dumpResponse(t *testing.T) func(res *http.Response, req *http.Request) error { + return func(res *http.Response, req *http.Request) error { + data, err := httputil.DumpResponse(res, true) + t.Logf("Response: %s \n", string(data)) + return err + } } // DumpResponse diff --git a/api_test/management_invite_test.go b/api_test/management_invite_test.go index 060ff919..6bdda75e 100644 --- a/api_test/management_invite_test.go +++ b/api_test/management_invite_test.go @@ -30,7 +30,7 @@ func TestManagementResetToken(t *testing.T) { Expires: time.Now().Add(time.Hour).Unix(), Host: u.Host, } - fmt.Println(sd.String()) + t.Log(sd.String()) signature := sig.SignString(sd.String(), []byte(cfg.ManagementKeySecret1)) request.Post("/management/token/reset_password"). @@ -42,7 +42,7 @@ func TestManagementResetToken(t *testing.T) { SetHeader(sig.KeyIDHeaderKey, cfg.ManagementKeyID1). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Type("json"). Status(200). AssertFunc(validateJSON(func(data map[string]interface{}) error { @@ -77,7 +77,7 @@ func TestManagementInactiveKey(t *testing.T) { Expires: time.Now().Add(time.Hour).Unix(), Host: u.Host, } - fmt.Println(sd.String()) + t.Log(sd.String()) signature := sig.SignString(sd.String(), []byte(cfg.ManagementKeySecret2)) body := "" @@ -91,7 +91,7 @@ func TestManagementInactiveKey(t *testing.T) { SetHeader(sig.KeyIDHeaderKey, cfg.ManagementKeyID2). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Status(400). AssertFunc(validateBodyText(func(b string) error { body = b @@ -115,7 +115,7 @@ func TestManagementInviteNoKeyID(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Status(400). AssertFunc(validateBodyText(func(b string) error { body = b @@ -141,7 +141,7 @@ func TestManagementInviteWrongKeyID(t *testing.T) { SetHeader("X-Nl-Key-Id", "AABBCCDDSS"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Status(400). AssertFunc(validateBodyText(func(b string) error { body = b diff --git a/api_test/misconfig_test/cors_test.go b/api_test/misconfig_test/cors_test.go index d2fbbe96..8201fd4b 100644 --- a/api_test/misconfig_test/cors_test.go +++ b/api_test/misconfig_test/cors_test.go @@ -16,7 +16,7 @@ func TestCorsAlwaysTrue(t *testing.T) { message = err["message"].(string) return nil })). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Status(500). Done() assert.NotEmpty(t, message) diff --git a/api_test/misconfig_test/main_test.go b/api_test/misconfig_test/main_test.go index 51b2bb26..650c72ca 100644 --- a/api_test/misconfig_test/main_test.go +++ b/api_test/misconfig_test/main_test.go @@ -18,6 +18,7 @@ import ( "github.com/caarlos0/env" "github.com/joho/godotenv" "github.com/madappgang/identifo/v2/config" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "gopkg.in/h2non/baloo.v3" "gopkg.in/h2non/baloo.v3/assert" @@ -69,7 +70,7 @@ func runServer() (model.Server, *httptest.Server) { os.Remove("./db.db") settings, _ = model.ConfigStorageSettingsFromString("file://./config.yaml") - configStorage, err := config.InitConfigurationStorage(settings) + configStorage, err := config.InitConfigurationStorage(logging.DefaultLogger, settings) if err != nil { log.Fatalf("Unable to load config with error: %v", err) } @@ -95,10 +96,12 @@ func stopServer(server *httptest.Server) { // Helper functions // DumpResponse -func dumpResponse(res *http.Response, req *http.Request) error { - data, err := httputil.DumpResponse(res, true) - fmt.Printf("Response: %s \n", string(data)) - return err +func dumpResponse(t *testing.T) func(res *http.Response, req *http.Request) error { + return func(res *http.Response, req *http.Request) error { + data, err := httputil.DumpResponse(res, true) + t.Logf("Response: %s \n", string(data)) + return err + } } // DumpResponse diff --git a/api_test/mongo_app_test.go b/api_test/mongo_app_test.go index 19c172b6..0635d7cf 100644 --- a/api_test/mongo_app_test.go +++ b/api_test/mongo_app_test.go @@ -4,6 +4,7 @@ import ( "os" "testing" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/mongo" "github.com/stretchr/testify/assert" @@ -17,10 +18,12 @@ func TestAppCRUD(t *testing.T) { connStr := os.Getenv("IDENTIFO_STORAGE_MONGO_CONN") - s, err := mongo.NewAppStorage(model.MongoDatabaseSettings{ - ConnectionString: connStr, - DatabaseName: "test_users", - }) + s, err := mongo.NewAppStorage( + logging.DefaultLogger, + model.MongoDatabaseSettings{ + ConnectionString: connStr, + DatabaseName: "test_users", + }) require.NoError(t, err) expectedApp := model.AppData{ diff --git a/api_test/mongo_user_integration_test.go b/api_test/mongo_user_integration_test.go index 50597866..37799802 100644 --- a/api_test/mongo_user_integration_test.go +++ b/api_test/mongo_user_integration_test.go @@ -4,6 +4,7 @@ import ( "os" "testing" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/mongo" "github.com/stretchr/testify/assert" @@ -18,10 +19,12 @@ func TestFetchUser(t *testing.T) { connStr := os.Getenv("IDENTIFO_STORAGE_MONGO_CONN") - s, err := mongo.NewUserStorage(model.MongoDatabaseSettings{ - ConnectionString: connStr, - DatabaseName: "test_users", - }) + s, err := mongo.NewUserStorage( + logging.DefaultLogger, + model.MongoDatabaseSettings{ + ConnectionString: connStr, + DatabaseName: "test_users", + }) require.NoError(t, err) s.(*mongo.UserStorage).ClearAllUserData() diff --git a/api_test/phone_login_test.go b/api_test/phone_login_test.go index 9cb66809..0a20750a 100644 --- a/api_test/phone_login_test.go +++ b/api_test/phone_login_test.go @@ -12,7 +12,7 @@ import ( // test happy day login with phone number for one user func TestLoginWithPhoneNumber(t *testing.T) { data := fmt.Sprintf(` - { + { "phone_number": "%s" }`, "+380123456789") signature, _ := Signature(data, cfg.AppSecret) @@ -23,13 +23,13 @@ func TestLoginWithPhoneNumber(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). Done() data2 := fmt.Sprintf(` - { + { "phone_number": "%s", "code": "%s", "scopes": [ @@ -44,7 +44,7 @@ func TestLoginWithPhoneNumber(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data2). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). @@ -54,7 +54,7 @@ func TestLoginWithPhoneNumber(t *testing.T) { // test happy day login with phone number for two users func TestLoginWithPhoneNumberTwoUsers(t *testing.T) { data := fmt.Sprintf(` - { + { "phone_number": "%s" }`, "+380123456781") signature, _ := Signature(data, cfg.AppSecret) @@ -65,13 +65,13 @@ func TestLoginWithPhoneNumberTwoUsers(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). Done() data2 := fmt.Sprintf(` - { + { "phone_number": "%s", "code": "%s", "scopes": [ @@ -86,14 +86,14 @@ func TestLoginWithPhoneNumberTwoUsers(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data2). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). Done() data = fmt.Sprintf(` - { + { "phone_number": "%s" }`, "+380123456782") signature, _ = Signature(data, cfg.AppSecret) @@ -104,13 +104,13 @@ func TestLoginWithPhoneNumberTwoUsers(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). Done() data2 = fmt.Sprintf(` - { + { "phone_number": "%s", "code": "%s", "scopes": [ @@ -125,7 +125,7 @@ func TestLoginWithPhoneNumberTwoUsers(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data2). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). diff --git a/api_test/redis_session_test.go b/api_test/redis_session_test.go index eebe9f26..641a80d9 100644 --- a/api_test/redis_session_test.go +++ b/api_test/redis_session_test.go @@ -5,6 +5,7 @@ import ( "testing" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/redis" "github.com/stretchr/testify/assert" @@ -22,7 +23,7 @@ func TestSessionStore(t *testing.T) { Address: rh, Prefix: "identifo", } - storage, err := redis.NewSessionStorage(s) + storage, err := redis.NewSessionStorage(logging.DefaultLogger, s) require.NoError(t, err) expDate := time.Date(2100, 1, 1, 0, 0, 0, 0, time.UTC) diff --git a/api_test/refresh_token_test.go b/api_test/refresh_token_test.go index c2dd989b..932d88ab 100644 --- a/api_test/refresh_token_test.go +++ b/api_test/refresh_token_test.go @@ -22,11 +22,11 @@ func TestLoginAndRefreshToken(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { rt = data["refresh_token"].(string) return nil @@ -43,7 +43,7 @@ func TestLoginAndRefreshToken(t *testing.T) { SetHeader("Authorization", "Bearer "+rt). SetHeader("X-Identifo-Timestamp", d). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_refresh_token.json"). @@ -66,11 +66,11 @@ func TestLoginAndRefreshTokenWithNewRefresh(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { rt = data["refresh_token"].(string) return nil @@ -87,7 +87,7 @@ func TestLoginAndRefreshTokenWithNewRefresh(t *testing.T) { SetHeader("Authorization", "Bearer "+rt). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_refresh_token_with_new_refresh.json"). diff --git a/api_test/register_test.go b/api_test/register_test.go index 063bc3c6..e063dcb5 100644 --- a/api_test/register_test.go +++ b/api_test/register_test.go @@ -22,7 +22,7 @@ func TestRegisterWithEmail(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/jwt_token_with_refresh_scheme.json"). @@ -49,7 +49,7 @@ func TestRegisterWithEmailAndLogout(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). AssertFunc(validateJSON(func(data map[string]interface{}) error { at = data["access_token"].(string) rt = data["refresh_token"].(string) @@ -73,7 +73,7 @@ func TestRegisterWithEmailAndLogout(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(logoutData). Expect(t). - // AssertFunc(dumpResponse). + // AssertFunc(dumpResponse(t)). Type("json"). Status(200). Done() diff --git a/api_test/reset_password_test.go b/api_test/reset_password_test.go index 34845447..10125d93 100644 --- a/api_test/reset_password_test.go +++ b/api_test/reset_password_test.go @@ -22,7 +22,7 @@ func TestResetPasswordWithCustomURL(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/response_ok.json"). @@ -53,7 +53,7 @@ func TestResetPasswordWithAppSpecificURL(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/response_ok.json"). @@ -83,7 +83,7 @@ func TestResetPasswordWithDefaultURL(t *testing.T) { SetHeader("Content-Type", "application/json"). BodyString(data). Expect(t). - AssertFunc(dumpResponse). + AssertFunc(dumpResponse(t)). Type("json"). Status(200). JSONSchema("../test/artifacts/api/response_ok.json"). diff --git a/config/config_test.go b/config/config_test.go index 531b36ac..cf233f4a 100644 --- a/config/config_test.go +++ b/config/config_test.go @@ -9,6 +9,7 @@ import ( "testing" "github.com/madappgang/identifo/v2/config" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -16,7 +17,7 @@ import ( func TestInitConfigurationWithEmptyFlags(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) - stor, err := config.InitConfigurationStorageFromFlag("") + stor, err := config.InitConfigurationStorageFromFlag(logging.DefaultLogger, "") require.NoError(t, err) @@ -32,7 +33,9 @@ func TestInitConfigurationWithEmptyFlags(t *testing.T) { func TestInitConfigurationWithFile(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) os.Mkdir("../data", os.ModePerm) - stor, err := config.InitConfigurationStorageFromFlag("file://../test/artifacts/configs/settings_with_default_storage.yaml") + stor, err := config.InitConfigurationStorageFromFlag( + logging.DefaultLogger, + "file://../test/artifacts/configs/settings_with_default_storage.yaml") require.NoError(t, err) // the settings are not loaded yet, should be empty @@ -61,7 +64,9 @@ func TestInitConfigurationWithFile(t *testing.T) { func TestInitConfigurationWithWrongFilePath(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) - stor, err := config.InitConfigurationStorageFromFlag("file://../test/artifacts/configs/settings_with_default_storage_not_exists.yaml") + stor, err := config.InitConfigurationStorageFromFlag( + logging.DefaultLogger, + "file://../test/artifacts/configs/settings_with_default_storage_not_exists.yaml") require.NoError(t, err) require.NotNil(t, stor) @@ -76,7 +81,9 @@ func TestInitConfigurationWithWrongFilePath(t *testing.T) { func TestInitConfigurationWithWrongSettingsData(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) - stor, err := config.InitConfigurationStorageFromFlag("file://../test/artifacts/configs/settings_with_wrong_data.yaml") + stor, err := config.InitConfigurationStorageFromFlag( + logging.DefaultLogger, + "file://../test/artifacts/configs/settings_with_wrong_data.yaml") require.NoError(t, err) require.NotNil(t, stor) @@ -101,7 +108,9 @@ func sliceContainsError(errs []error, text string) bool { func TestInitConfigurationWithDefaultReferenceDefault(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) - stor, err := config.InitConfigurationStorageFromFlag("file://../test/artifacts/configs/settings_with_default_reference_default.yaml") + stor, err := config.InitConfigurationStorageFromFlag( + logging.DefaultLogger, + "file://../test/artifacts/configs/settings_with_default_reference_default.yaml") require.NoError(t, err) require.NotNil(t, stor) @@ -117,7 +126,9 @@ func TestInitConfigurationWithDefaultReferenceDefault(t *testing.T) { func TestInitConfigurationWithBrokenSettingsAPICall(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) - stor, _ := config.InitConfigurationStorageFromFlag("file://../test/artifacts/configs/settings_with_default_reference_default.yaml") + stor, _ := config.InitConfigurationStorageFromFlag( + logging.DefaultLogger, + "file://../test/artifacts/configs/settings_with_default_reference_default.yaml") s, errs := stor.LoadServerSettings(true) assert.NotEmpty(t, errs) assert.True(t, sliceContainsError(errs, "DefaultStorage settings could not be of type Default")) @@ -159,7 +170,9 @@ func TestInitConfigurationWithBrokenSettingsAPICall(t *testing.T) { func TestInitConfigurationWithWithGoodConfigAndFailedStorages(t *testing.T) { os.Unsetenv(model.IdentifoConfigPathEnvName) // storages will failed to create as folder does not exists - stor, err := config.InitConfigurationStorageFromFlag("file://../test/artifacts/configs/settings_with_wrong_file_path.yaml") + stor, err := config.InitConfigurationStorageFromFlag( + logging.DefaultLogger, + "file://../test/artifacts/configs/settings_with_wrong_file_path.yaml") require.NoError(t, err) // the settings are not loaded yet, should be empty diff --git a/config/config_watcher.go b/config/config_watcher.go index e2e516d9..3385fc55 100644 --- a/config/config_watcher.go +++ b/config/config_watcher.go @@ -3,6 +3,7 @@ package config import ( "errors" "fmt" + "log/slog" "time" "github.com/madappgang/identifo/v2/model" @@ -11,7 +12,7 @@ import ( const defaultS3PollInterval = time.Minute // poll new updates every minute -func NewConfigWatcher(settings model.FileStorageSettings) (model.ConfigurationWatcher, error) { +func NewConfigWatcher(logger *slog.Logger, settings model.FileStorageSettings) (model.ConfigurationWatcher, error) { filename := settings.FileName() switch settings.Type { case model.FileStorageTypeS3: @@ -25,13 +26,13 @@ func NewConfigWatcher(settings model.FileStorageSettings) (model.ConfigurationWa } settings.Local.Path = settings.Dir() // remove filename from key to keep dir only default: - return nil, fmt.Errorf("Unsupported config storage type: %v", settings.Type) + return nil, fmt.Errorf("unsupported config storage type: %v", settings.Type) } fs, err := storage.NewFS(settings) if err != nil { return nil, err } - watcher := storage.NewFSWatcher(fs, []string{filename}, defaultS3PollInterval) + watcher := storage.NewFSWatcher(logger, fs, []string{filename}, defaultS3PollInterval) return watcher, nil } diff --git a/config/configurator.go b/config/configurator.go index 4b7c389f..60961854 100644 --- a/config/configurator.go +++ b/config/configurator.go @@ -3,11 +3,12 @@ package config import ( "fmt" "io/fs" - "log" + "log/slog" "time" imp "github.com/madappgang/identifo/v2/impersonation/local" impPlugin "github.com/madappgang/identifo/v2/impersonation/plugin" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/server" "github.com/madappgang/identifo/v2/services/mail" @@ -40,15 +41,23 @@ var defaultEmailTemplateFSSettings = model.FileStorageSettings{ // NewServer creates new server instance from ServerSettings func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (model.Server, error) { + defaultLogger := logging.NewDefaultLogger().With(logging.FieldComponent, "configurator") + var errs []error // read settings, if they empty or use cached version settings, e := config.LoadServerSettings(true) if len(e) > 0 { - log.Printf("Error on Load Server Settings: %+v\n", e) + defaultLogger.Error("Error on Load Server Settings", logging.FieldErrors, e) settings = model.DefaultServerSettings errs = e } + baseLogger := logging.NewLogger( + settings.Logger.Format, + settings.Logger.Level) + + logger := baseLogger.With(logging.FieldComponent, "configurator") + // helper function get settings from default or override dbSettings := func(s model.DatabaseSettings) model.DatabaseSettings { if s.Type == model.DBTypeDefault { @@ -58,57 +67,57 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode } // Create all storages - app, err := storage.NewAppStorage(dbSettings(settings.Storage.AppStorage)) + app, err := storage.NewAppStorage(baseLogger, dbSettings(settings.Storage.AppStorage)) if err != nil { - log.Printf("Error on Create New AppStorage %v", err) + logger.Error("Error on Create New AppStorage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating app storage: %v", err)) } - user, err := storage.NewUserStorage(dbSettings(settings.Storage.UserStorage)) + user, err := storage.NewUserStorage(baseLogger, dbSettings(settings.Storage.UserStorage)) if err != nil { - log.Printf("Error on Create New user storage %v", err) + logger.Error("Error on Create New user storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating user storage: %v", err)) } - token, err := storage.NewTokenStorage(dbSettings(settings.Storage.TokenStorage)) + token, err := storage.NewTokenStorage(baseLogger, dbSettings(settings.Storage.TokenStorage)) if err != nil { - log.Printf("Error on Create New token storage %v", err) + logger.Error("Error on Create New token storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating token storage: %v", err)) } - tokenBlacklist, err := storage.NewTokenBlacklistStorage(dbSettings(settings.Storage.TokenBlacklist)) + tokenBlacklist, err := storage.NewTokenBlacklistStorage(baseLogger, dbSettings(settings.Storage.TokenBlacklist)) if err != nil { - log.Printf("Error on Create New blacklist storage %v", err) + logger.Error("Error on Create New blacklist storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating blacklist storage: %v", err)) } - verification, err := storage.NewVerificationCodesStorage(dbSettings(settings.Storage.VerificationCodeStorage)) + verification, err := storage.NewVerificationCodesStorage(baseLogger, dbSettings(settings.Storage.VerificationCodeStorage)) if err != nil { - log.Printf("Error on Create New verification codes storage %v", err) + logger.Error("Error on Create New verification codes storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating verification codes storage: %v", err)) } - invite, err := storage.NewInviteStorage(dbSettings(settings.Storage.InviteStorage)) + invite, err := storage.NewInviteStorage(baseLogger, dbSettings(settings.Storage.InviteStorage)) if err != nil { - log.Printf("Error on Create New invite storage %v", err) + logger.Error("Error on Create New invite storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating invite storage: %v", err)) } - managementKeys, err := storage.NewManagementKeys(dbSettings(settings.Storage.ManagementKeysStorage)) + managementKeys, err := storage.NewManagementKeys(baseLogger, dbSettings(settings.Storage.ManagementKeysStorage)) if err != nil { - log.Printf("Error on Create New management keys storage %v", err) + logger.Error("Error on Create New management keys storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating management keys storage: %v", err)) } - session, err := storage.NewSessionStorage(settings.SessionStorage) + session, err := storage.NewSessionStorage(baseLogger, settings.SessionStorage) if err != nil { - log.Printf("Error on Create New session storage %v", err) + logger.Error("Error on Create New session storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating session storage: %v", err)) } - key, err := storage.NewKeyStorage(settings.KeyStorage) + key, err := storage.NewKeyStorage(baseLogger, settings.KeyStorage) if err != nil { - log.Printf("Error on Create New key storage %v", err) + logger.Error("Error on Create New key storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating key storage: %v", err)) } @@ -121,7 +130,7 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode } loginFS, err := storage.NewFS(lwas) if err != nil { - log.Printf("Error creating login fs storage %v", err) + logger.Error("Error creating login fs storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating login fs storage: %v", err)) } @@ -129,7 +138,7 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode if settings.AdminPanel.Enabled { adminPanelFS, err = storage.NewFS(adminPanelFSSettings) if err != nil { - log.Printf("Error creating admin panel fs storage %v", err) + logger.Error("Error creating admin panel fs storage", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating admin panel fs storage: %v", err)) } } @@ -150,9 +159,9 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode } // create 3rd party services - sms, err := sms.NewService(settings.Services.SMS) + sms, err := sms.NewService(baseLogger, settings.Services.SMS) if err != nil { - log.Printf("Error creating SMS service %v", err) + logger.Error("Error creating SMS service %v", err) errs = append(errs, fmt.Errorf("error creating SMS service: %v", err)) } @@ -163,21 +172,21 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode } emailTemplateFS, err := storage.NewFS(ets) if err != nil { - log.Printf("Error creating email template filesystem %v", err) + logger.Error("Error creating email template filesystem", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating email template filesystem: %v", err)) } emailServiceSettings := settings.Services.Email // update templates every five minutes and look templates in a root folder of FS - email, err := mail.NewService(emailServiceSettings, emailTemplateFS, time.Minute*5, "") + email, err := mail.NewService(baseLogger, emailServiceSettings, emailTemplateFS, time.Minute*5, "") if err != nil { - log.Printf("Error creating email service %v", err) + logger.Error("Error creating email service", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating email service: %v", err)) } - tokenS, err := NewTokenService(settings.General, sc) + tokenS, err := NewTokenService(baseLogger, settings.General, sc) if err != nil { - log.Printf("Error creating token service %v", err) + logger.Error("Error creating token service", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating token service: %v", err)) } @@ -185,7 +194,7 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode impS, err := NewImpersonationProvider(settings.Impersonation) if err != nil { - log.Printf("Error creating impersonation provider %v", err) + logger.Error("Error creating impersonation provider", logging.FieldError, err) errs = append(errs, fmt.Errorf("error creating impersonation provider: %v", err)) } @@ -205,13 +214,18 @@ func NewServer(config model.ConfigurationStorage, restartChan chan<- bool) (mode return server, nil } -func NewTokenService(settings model.GeneralServerSettings, storages model.ServerStorageCollection) (model.TokenService, error) { +func NewTokenService( + logger *slog.Logger, + settings model.GeneralServerSettings, + storages model.ServerStorageCollection, +) (model.TokenService, error) { key, err := storages.Key.LoadPrivateKey() if err != nil { return nil, err } tokenService, err := jwt.NewJWTokenService( + logger, key, settings.Issuer, storages.Token, diff --git a/config/storage.go b/config/storage.go index ed378195..0f580734 100644 --- a/config/storage.go +++ b/config/storage.go @@ -2,7 +2,7 @@ package config import ( "fmt" - "log" + "log/slog" "os" "github.com/madappgang/identifo/v2/model" @@ -11,74 +11,78 @@ import ( ) // InitConfigurationStorage initializes configuration storage. -func InitConfigurationStorage(config model.FileStorageSettings) (model.ConfigurationStorage, error) { +func InitConfigurationStorage( + logger *slog.Logger, + config model.FileStorageSettings, +) (model.ConfigurationStorage, error) { switch config.Type { // case model.ConfigStorageTypeEtcd: // return etcd.NewConfigurationStorage(config) case model.FileStorageTypeS3: - return s3.NewConfigurationStorage(config) + return s3.NewConfigurationStorage(logger, config) case model.FileStorageTypeLocal: - return fs.NewConfigurationStorage(config) + return fs.NewConfigurationStorage(logger, config) default: return nil, fmt.Errorf("config type is not supported") } } // DefaultStorage trying to create a default storage with default file -func DefaultStorage() model.ConfigurationStorage { - return fs.NewDefaultConfigurationStorage() +func DefaultStorage(logger *slog.Logger) model.ConfigurationStorage { + return fs.NewDefaultConfigurationStorage(logger) } -func InitConfigurationStorageFromFlag(configFlag string) (model.ConfigurationStorage, error) { +// InitConfigurationStorageFromFlag initializes configuration storage from flag. +// config storage should: +// load default settings if the originals settings file is unavailable +// continue check desired config location in case the proper config file appear +// validate config settings +// if server settings are invalid - load fallback settings and mark itself ad invalid +// continue to listen for file location and reload it in case it changed +// +// this means that the location for settings is valid +// but settings are invalid or unreachable +// both things could be fixed while the app is running +// that is why Identifo should run, letting the admin to fix it +func InitConfigurationStorageFromFlag(logger *slog.Logger, configFlag string) (model.ConfigurationStorage, error) { // trying to get server settings from env variable if len(configFlag) == 0 { configFlag = os.Getenv(model.IdentifoConfigPathEnvName) } // if we have no config flag available and not env variable set, just load default config file if len(configFlag) == 0 { - log.Println("Config Storage: not config flag specified, I am loading default build in config file") - return DefaultStorage(), nil + logger.Info("Config Storage: not config flag specified, I am loading default build in config file") + return DefaultStorage(logger), nil } // if config settings are invalid and not empty we should stop the app // as it means the service is misconfigured and could not works at all settings, err := model.ConfigStorageSettingsFromString(configFlag) if err != nil { - return nil, fmt.Errorf("Unable to init config using\n\tconfig string: %s\n\twith error: %v\nT", + return nil, fmt.Errorf("unable to init config using\n\tconfig string: %s\n\twith error: %v\nT", configFlag, err, ) } - configStorage, err := InitConfigurationStorage(settings) + configStorage, err := InitConfigurationStorage(logger, settings) if err != nil { - return nil, fmt.Errorf("Unable to init config using\n\tconfig string: %s\n\twith error: %v\nT", + return nil, fmt.Errorf("unable to init config using\n\tconfig string: %s\n\twith error: %v\nT", configFlag, err) } return configStorage, nil } -func NewServerFromFlag(configFlag string, restartChan chan<- bool) (model.Server, error) { - configStorage, err := InitConfigurationStorageFromFlag(configFlag) +func NewServerFromFlag(logger *slog.Logger, configFlag string, restartChan chan<- bool) (model.Server, error) { + configStorage, err := InitConfigurationStorageFromFlag(logger, configFlag) if err != nil { - return nil, fmt.Errorf("Unable to load settings on start with error: %v ", err) + return nil, fmt.Errorf("unable to load settings on start with error: %w", err) } - // config storage should: - // load default settings if the originals settings file is unavailable - // continue check desired config location in case the proper config file appear - // validate config settings - // if server settings are invalid - load fallback settings and mark itself ad invalid - // continue to listen for file location and reload it in case it changed - // - // this means that the location for settings is valid - // but settings are invalid or unreachable - // both things could be fixed while the app is running - // that is why Identifo should run, letting the admin to fix it srv, err := NewServer(configStorage, restartChan) if err != nil { - return nil, fmt.Errorf("Unable to create server with error: %v ", err) + return nil, fmt.Errorf("unable to create server with error: %w", err) } return srv, nil diff --git a/config/storage_test.go b/config/storage_test.go index 9b0bed1b..a02a3e4b 100644 --- a/config/storage_test.go +++ b/config/storage_test.go @@ -3,6 +3,7 @@ package config import ( "testing" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/stretchr/testify/require" ) @@ -18,6 +19,6 @@ func TestInitConfigurationStorage(t *testing.T) { }, } - _, err := InitConfigurationStorage(config) + _, err := InitConfigurationStorage(logging.DefaultLogger, config) require.NoError(t, err) } diff --git a/impersonation/plugin/provider.go b/impersonation/plugin/provider.go index 6419db09..d9633da5 100644 --- a/impersonation/plugin/provider.go +++ b/impersonation/plugin/provider.go @@ -1,6 +1,7 @@ package plugin import ( + "os" "os/exec" "time" @@ -18,12 +19,19 @@ func NewImpersonationProvider(settings model.PluginSettings, timeout time.Durati params = append(params, v) } - client := plugin.NewClient(&plugin.ClientConfig{ + cfg := &plugin.ClientConfig{ HandshakeConfig: shared.Handshake, Plugins: shared.PluginMap, Cmd: exec.Command(settings.Cmd, params...), AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, - }) + } + + if settings.RedirectStd { + cfg.SyncStdout = os.Stdout + cfg.SyncStderr = os.Stderr + } + + client := plugin.NewClient(cfg) // Connect via RPC rpcClient, err := client.Client() diff --git a/jwt/pem.go b/jwt/pem.go index f715f0bd..6d2f5b3a 100644 --- a/jwt/pem.go +++ b/jwt/pem.go @@ -45,7 +45,7 @@ func LoadPrivateKeyFromPEMString(s string) (interface{}, model.TokenSignatureAlg } return private, model.TokenSignatureAlgorithmES256, nil default: - return nil, model.TokenSignatureAlgorithmInvalid, fmt.Errorf("could not load unsupported key type: %T\n", private) + return nil, model.TokenSignatureAlgorithmInvalid, fmt.Errorf("could not load unsupported key type: %T", private) } } @@ -76,7 +76,7 @@ func LoadPublicKeyFromString(s string) (interface{}, model.TokenSignatureAlgorit case *ecdsa.PublicKey: return pub, model.TokenSignatureAlgorithmES256, nil default: - return nil, model.TokenSignatureAlgorithmInvalid, fmt.Errorf("could not load unsupported key type: %T\n", pub) + return nil, model.TokenSignatureAlgorithmInvalid, fmt.Errorf("could not load unsupported key type: %T", pub) } } @@ -142,6 +142,6 @@ func GenerateNewPrivateKey(alg model.TokenSignatureAlgorithm) (interface{}, erro case model.TokenSignatureAlgorithmES256: return ecdsa.GenerateKey(elliptic.P256(), rand.Reader) default: - return nil, fmt.Errorf("unable to generate new private key, unsupported algorithm: %s\n", alg) + return nil, fmt.Errorf("unable to generate new private key, unsupported algorithm: %s", alg) } } diff --git a/jwt/rsa_test.go b/jwt/rsa_test.go index c61bed23..30b3f4c6 100644 --- a/jwt/rsa_test.go +++ b/jwt/rsa_test.go @@ -98,12 +98,6 @@ func TestKeysManualSerializationServiceRSA(t *testing.T) { } } -func printByte(s []byte) { - for _, i := range s { - fmt.Printf("%X", i) - } -} - func TestRSAPemMarshalling(t *testing.T) { private, alg, err := jwti.LoadPrivateKeyFromPEMString(string(privateRSAKeyPEM)) if err != nil { diff --git a/jwt/service/jwt_token_service.go b/jwt/service/jwt_token_service.go index 3ce3bc59..68094e99 100644 --- a/jwt/service/jwt_token_service.go +++ b/jwt/service/jwt_token_service.go @@ -8,6 +8,7 @@ import ( "encoding/base64" "errors" "fmt" + "log/slog" "strings" jwt "github.com/golang-jwt/jwt/v4" @@ -45,12 +46,21 @@ const ( // Arguments: // - privateKeyPath - the path to the private key in pem format. Please keep it in a secret place. // - publicKeyPath - the path to the public key. -func NewJWTokenService(privateKey interface{}, issuer string, tokenStorage model.TokenStorage, appStorage model.AppStorage, userStorage model.UserStorage, options ...func(model.TokenService) error) (model.TokenService, error) { +func NewJWTokenService( + logger *slog.Logger, + privateKey interface{}, + issuer string, + tokenStorage model.TokenStorage, + appStorage model.AppStorage, + userStorage model.UserStorage, + options ...func(model.TokenService) error, +) (model.TokenService, error) { if privateKey == nil { return nil, fmt.Errorf("private key is empty") } t := &JWTokenService{ + logger: logger, issuer: issuer, tokenStorage: tokenStorage, appStorage: appStorage, @@ -72,6 +82,8 @@ func NewJWTokenService(privateKey interface{}, issuer string, tokenStorage model // JWTokenService is a JWT token service. type JWTokenService struct { + logger *slog.Logger + privateKey interface{} // *ecdsa.PrivateKey, or *rsa.PrivateKey tokenStorage model.TokenStorage appStorage model.AppStorage @@ -132,14 +144,16 @@ func (ts *JWTokenService) PublicKey() interface{} { pk := ts.privateKey.(*ecdsa.PrivateKey) ts.cachedPublicKey = pk.Public() default: - fmt.Printf("unable to get public key from private key of type: %v", t) + ts.logger.Error("unable to get public key from private key", + "type", t) return nil } return ts.cachedPublicKey } func (ts *JWTokenService) SetPrivateKey(key interface{}) { - fmt.Printf("Changing private key for Token service, all new tokens will be signed with a new key!!!\n") + ts.logger.Info("Changing private key for Token service, all new tokens will be signed with a new key!!!") + ts.privateKey = key ts.cachedPublicKey = nil ts.cachedAlgorithm = "" diff --git a/jwt/token_test.go b/jwt/token_test.go index 97d90821..15d2448e 100644 --- a/jwt/token_test.go +++ b/jwt/token_test.go @@ -5,6 +5,7 @@ import ( "testing" jwt "github.com/madappgang/identifo/v2/jwt/service" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage" @@ -30,23 +31,26 @@ func createTokenService(t *testing.T) model.TokenService { if err != nil { t.Fatalf("Unable to create token storage %v", err) } - as, err := mem.NewAppStorage() + as, err := mem.NewAppStorage(logging.DefaultLogger) if err != nil { t.Fatalf("Unable to create app storage %v", err) } - keyStorage, err := storage.NewKeyStorage(model.FileStorageSettings{ - Type: model.FileStorageTypeLocal, - Local: model.FileStorageLocal{ - Path: keyPath, - }, - }) + keyStorage, err := storage.NewKeyStorage( + logging.DefaultLogger, + model.FileStorageSettings{ + Type: model.FileStorageTypeLocal, + Local: model.FileStorageLocal{ + Path: keyPath, + }, + }) require.NoError(t, err) privateKey, err := keyStorage.LoadPrivateKey() require.NoError(t, err) tokenService, err := jwt.NewJWTokenService( + logging.DefaultLogger, privateKey, testIssuer, tstor, diff --git a/localization/localization.go b/localization/localization.go index 04b7ad0f..02275835 100644 --- a/localization/localization.go +++ b/localization/localization.go @@ -2,11 +2,11 @@ package localization import ( "embed" - "fmt" "io/fs" "path/filepath" "strings" + "github.com/madappgang/identifo/v2/logging" "golang.org/x/text/language" "golang.org/x/text/message" "gopkg.in/yaml.v2" @@ -44,7 +44,9 @@ func LoadDefaultCatalog() error { tagStr := strings.TrimSuffix(d.Name(), filepath.Ext(d.Name())) tag, err := language.Parse(tagStr) if err != nil { - fmt.Printf("unable to load translation file %s, as could not construct language tag from file name with error: %s\n", d.Name(), err.Error()) + logging.DefaultLogger.Info("Unable to load translation file, as could not construct language tag from file name with error", + "file", d.Name(), + logging.FieldError, err) // not returning error, just moving forward to other files to try to load other languages return nil } diff --git a/logging/default.go b/logging/default.go new file mode 100644 index 00000000..3e27b950 --- /dev/null +++ b/logging/default.go @@ -0,0 +1,43 @@ +package logging + +import ( + "log/slog" + "os" +) + +var DefaultLogger = NewDefaultLogger() + +func NewDefaultLogger() *slog.Logger { + return NewLogger("json", "info") +} + +func NewLogger(format, level string) *slog.Logger { + o := &slog.HandlerOptions{ + Level: getLogLevel(level), + } + + var h slog.Handler + + if format == "text" { + h = slog.NewTextHandler(os.Stdout, o) + } else { + h = slog.NewJSONHandler(os.Stdout, o) + } + + return slog.New(h) +} + +func getLogLevel(level string) slog.Level { + switch level { + case "debug": + return slog.LevelDebug + case "info": + return slog.LevelInfo + case "warn": + return slog.LevelWarn + case "error": + return slog.LevelError + default: + return slog.LevelInfo + } +} diff --git a/logging/fields.go b/logging/fields.go new file mode 100644 index 00000000..d328c16b --- /dev/null +++ b/logging/fields.go @@ -0,0 +1,12 @@ +package logging + +const ( + FieldComponent = "component" + FieldError = "err" + FieldErrors = "errs" + FieldErrorID = "errId" + FieldAppID = "appId" + FieldUserID = "userId" + FieldEmail = "email" + FieldURL = "url" +) diff --git a/main.go b/main.go index 8544580b..376d5c12 100644 --- a/main.go +++ b/main.go @@ -4,7 +4,7 @@ import ( "context" "flag" "fmt" - "log" + "log/slog" "net/http" "os" "os/signal" @@ -13,6 +13,7 @@ import ( "github.com/madappgang/identifo/v2/config" "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -29,17 +30,32 @@ func main() { defer close(done) defer close(restart) - srv, httpSrv, err := initServer(*configFlag, restart) + defaultLogger := logging.NewDefaultLogger() + + srv, httpSrv, err := initServer(defaultLogger, *configFlag, restart) if err != nil { - log.Fatalf("Unable to start Identifo with error: %v ", err) + defaultLogger.Error("Unable to start Identifo with error", logging.FieldError, err) + os.Exit(1) } - go startHTTPServer(httpSrv) - log.Printf("Started the server on port: %s", srv.Settings().GetPort()) - log.Printf("You can open admin panel: %s/adminpanel or http://localhost:%s/adminpanel", srv.Settings().General.Host, srv.Settings().GetPort()) - watcher, err := config.NewConfigWatcher(srv.Settings().Config) + settings := srv.Settings() + + logSettings := settings.Logger + logger := logging.NewLogger(logSettings.Format, logSettings.Level) + + logging.DefaultLogger = logger + + go startHTTPServer(logger, httpSrv) + + logger.Info("Started the server", "port", srv.Settings().GetPort()) + logger.Info("You can open admin panel", + "host", fmt.Sprintf("%s/adminpanel", settings.General.Host), + "url", fmt.Sprintf("http://localhost:%s/adminpanel", settings.GetPort())) + + watcher, err := config.NewConfigWatcher(logger, srv.Settings().Config) if err != nil { - log.Fatalf("Unable to start Identifo with error: %v ", err) + logger.Error("Unable to start Identifo", logging.FieldError, err) + os.Exit(3) } watcher.Watch() @@ -47,59 +63,72 @@ func main() { signal.Notify(osch, syscall.SIGINT, syscall.SIGTERM) restartServer := func() { - ctx, _ := context.WithTimeout(context.Background(), time.Minute*3) - httpSrv.Shutdown(ctx) + closeCtx, cancel := context.WithTimeout(context.Background(), time.Minute*3) + httpSrv.Shutdown(closeCtx) + cancel() srv.Close() // TODO: implement graceful server shutdown - srv, httpSrv, err = initServer(*configFlag, restart) + + srv, httpSrv, err = initServer(logger, *configFlag, restart) if err != nil { - log.Fatalf("Unable to start Identifo with error: %v ", err) + logger.Error("Unable to restart Identifo", logging.FieldError, err) + os.Exit(4) } - go startHTTPServer(httpSrv) - log.Printf("Started the server on port: %s", srv.Settings().GetPort()) - log.Printf("You can open admin panel: %s/adminpanel or http://localhost:%s/adminpanel", srv.Settings().General.Host, srv.Settings().GetPort()) - log.Println("Server successfully restarted with new settings ...") + go startHTTPServer(logger, httpSrv) + + logger.Info("Started the server", "port", srv.Settings().GetPort()) + logger.Info("You can open admin panel", + "host", fmt.Sprintf("%s/adminpanel", settings.General.Host), + "url", fmt.Sprintf("http://localhost:%s/adminpanel", settings.GetPort())) + logger.Info("Server successfully restarted with new settings ...") } for { select { case <-watcher.WatchChan(): - log.Println("Config file has been changed, restarting ...") + logger.Info("Config file has been changed, restarting ...") restartServer() case <-restart: - log.Println("Restart signal have been received, restarting ...") + logger.Info("Restart signal have been received, restarting ...") restartServer() case err := <-watcher.ErrorChan(): - log.Printf("Getting error from config watcher: %v", err) + logger.Error("Getting error from config watcher", logging.FieldError, err) case <-osch: - log.Println("Received termination signal, shutting down the server โคต๏ธ...") - ctx, _ := context.WithTimeout(context.Background(), time.Minute*3) - httpSrv.Shutdown(ctx) + logger.Info("Received termination signal, shutting down the server โคต๏ธ...") + closeCtx, cancel := context.WithTimeout(context.Background(), time.Minute*3) + httpSrv.Shutdown(closeCtx) + cancel() srv.Close() - log.Println("The server is down, good bye ๐Ÿ‘‹๐Ÿ‘‹๐Ÿ‘‹.") + logger.Info("The server is down, good bye ๐Ÿ‘‹๐Ÿ‘‹๐Ÿ‘‹.") return } } } -func initServer(flag string, restartChan chan<- bool) (model.Server, *http.Server, error) { - srv, err := config.NewServerFromFlag(flag, restartChan) +func initServer(logger *slog.Logger, flag string, restartChan chan<- bool) (model.Server, *http.Server, error) { + srv, err := config.NewServerFromFlag(logger, flag, restartChan) if err != nil { - return nil, nil, fmt.Errorf("Unable to start Identifo with error: %v ", err) + return nil, nil, fmt.Errorf("unable to start Identifo with error: %w", err) } + httpSrv := &http.Server{ Addr: srv.Settings().GetPort(), Handler: srv.Router(), } + return srv, httpSrv, nil } -func startHTTPServer(server *http.Server) { +func startHTTPServer( + logger *slog.Logger, + server *http.Server, +) { if err := server.ListenAndServe(); err != http.ErrServerClosed { - log.Fatalf("ListenAndServe() error: %v", err) + logger.Error("ListenAndServe()", logging.FieldError, err) + os.Exit(2) } - log.Print("Server stopped") + logger.Info("Server stopped") } diff --git a/model/app_storage.go b/model/app_storage.go index ee7a6e0a..6c8911ad 100644 --- a/model/app_storage.go +++ b/model/app_storage.go @@ -103,6 +103,7 @@ const ( type TokenPayloadServicePluginSettings struct { Name string `json:"name" bson:"name,omitempty"` Cmd string `json:"cmd" bson:"cmd,omitempty"` + RedirectStd bool `json:"redirect_std" bson:"redirect_std,omitempty"` Params map[string]string `json:"params" bson:"params,omitempty"` ClientTimeout time.Duration `json:"client_timeout" bson:"client_timeout,omitempty"` } diff --git a/model/server_settings.go b/model/server_settings.go index 544c3d43..b4c00b34 100644 --- a/model/server_settings.go +++ b/model/server_settings.go @@ -125,8 +125,9 @@ type DynamoDatabaseSettings struct { } type PluginSettings struct { - Cmd string `yaml:"cmd" json:"cmd"` - Params map[string]string `yaml:"params" json:"params"` + Cmd string `yaml:"cmd" json:"cmd"` + RedirectStd bool `yaml:"redirectStd" json:"redirectStd"` + Params map[string]string `yaml:"params" json:"params"` } type GRPCSettings struct { @@ -346,7 +347,9 @@ func (ss ServerSettings) GetPort() string { } type LoggerSettings struct { - DumpRequest bool `yaml:"dumpRequest" json:"dumpRequest"` + DumpRequest bool `yaml:"dumpRequest" json:"dumpRequest"` + Format string `yaml:"format" json:"format"` + Level string `yaml:"level" json:"level"` } type AdminPanelSettings struct { diff --git a/model/user_storage.go b/model/user_storage.go index 366fc120..01418a66 100644 --- a/model/user_storage.go +++ b/model/user_storage.go @@ -1,14 +1,14 @@ package model import ( + "crypto/rand" "encoding/json" "errors" - "log" - "math/rand" "regexp" "strings" "time" + "github.com/madappgang/identifo/v2/logging" "golang.org/x/crypto/bcrypt" ) @@ -130,7 +130,7 @@ type TFAInfo struct { func UserFromJSON(d []byte) (User, error) { var user User if err := json.Unmarshal(d, &user); err != nil { - log.Println("Error while unmarshal user:", err) + logging.DefaultLogger.Error("Error while unmarshal user", logging.FieldError, err) return User{}, err } return user, nil @@ -144,7 +144,6 @@ func PasswordHash(pwd string) string { // RandomPassword creates random password func RandomPassword(length int) string { - rand.Seed(time.Now().UnixNano()) return randSeq(length) } @@ -152,9 +151,17 @@ var rndPassLetters = []rune("abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXY func randSeq(n int) string { b := make([]rune, n) + + rnd := make([]byte, n) + rand.Read(rnd) + + charSetLen := byte(len(rndPassLetters)) + for i := range b { - b[i] = rndPassLetters[rand.Intn(len(rndPassLetters))] + ix := rnd[i] % charSetLen + b[i] = rndPassLetters[ix] } + return string(b) } diff --git a/model/user_storage_test.go b/model/user_storage_test.go new file mode 100644 index 00000000..9255280c --- /dev/null +++ b/model/user_storage_test.go @@ -0,0 +1,18 @@ +package model + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestPasswordGen(t *testing.T) { + pass := randSeq(12) + assert.Len(t, pass, 12) + + pass = randSeq(256) + assert.Len(t, pass, 256) + + pass = randSeq(1) + assert.Len(t, pass, 1) +} diff --git a/plugins/bolt-user-storage/main.go b/plugins/bolt-user-storage/main.go index 9fbc8582..eff49faa 100644 --- a/plugins/bolt-user-storage/main.go +++ b/plugins/bolt-user-storage/main.go @@ -2,12 +2,12 @@ package main import ( "flag" - "log" "os" "os/signal" "syscall" "github.com/hashicorp/go-plugin" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" "github.com/madappgang/identifo/v2/storage/plugin/shared" @@ -17,9 +17,11 @@ func main() { path := flag.String("path", "", "path to database") flag.Parse() - s, err := boltdb.NewUserStorage(model.BoltDBDatabaseSettings{ - Path: *path, - }) + s, err := boltdb.NewUserStorage( + logging.DefaultLogger, + model.BoltDBDatabaseSettings{ + Path: *path, + }) if err != nil { panic(err) @@ -40,10 +42,7 @@ func main() { osch := make(chan os.Signal, 1) signal.Notify(osch, syscall.SIGHUP, syscall.SIGINT, syscall.SIGTERM, syscall.SIGQUIT) - for { - <-osch - s.Close() - log.Println("Boltdb user storage is terminated.") - return - } + <-osch + s.Close() + logging.DefaultLogger.Info("Boltdb user storage is terminated.") } diff --git a/plugins/mongo-user-storage/main.go b/plugins/mongo-user-storage/main.go index d0aa0c7a..75a42f3d 100644 --- a/plugins/mongo-user-storage/main.go +++ b/plugins/mongo-user-storage/main.go @@ -2,12 +2,12 @@ package main import ( "flag" - "log" "os" "os/signal" "syscall" "github.com/hashicorp/go-plugin" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/mongo" "github.com/madappgang/identifo/v2/storage/plugin/shared" @@ -18,10 +18,12 @@ func main() { databaseName := flag.String("database", "", "name of database") flag.Parse() - s, err := mongo.NewUserStorage(model.MongoDatabaseSettings{ - ConnectionString: *connectionString, - DatabaseName: *databaseName, - }) + s, err := mongo.NewUserStorage( + logging.DefaultLogger, + model.MongoDatabaseSettings{ + ConnectionString: *connectionString, + DatabaseName: *databaseName, + }) if err != nil { panic(err) } @@ -43,5 +45,5 @@ func main() { <-osch s.Close() - log.Println("Mongo user storage is terminated.") + logging.DefaultLogger.Info("Mongo user storage is terminated.") } diff --git a/server-config.yaml b/server-config.yaml index cebd2b04..be2e7670 100644 --- a/server-config.yaml +++ b/server-config.yaml @@ -108,5 +108,7 @@ services: # source: whatever # RouteMobile-related setting. # region: australia # RouteMobile-related setting. Supported values are: uae. - - +logger: + dumpRequest: false + format: json + level: debug diff --git a/server/server.go b/server/server.go index 1bfa6720..f8f8a929 100644 --- a/server/server.go +++ b/server/server.go @@ -12,7 +12,12 @@ import ( ) // NewServer creates backend service. -func NewServer(storages model.ServerStorageCollection, services model.ServerServices, errs []error, restartChan chan<- bool) (model.Server, error) { +func NewServer( + storages model.ServerStorageCollection, + services model.ServerServices, + errs []error, + restartChan chan<- bool, +) (model.Server, error) { if storages.Config == nil { return nil, fmt.Errorf("unable create sever with empty config storage") } diff --git a/services/mail/mail.go b/services/mail/mail.go index 63d0ac02..b16d7064 100644 --- a/services/mail/mail.go +++ b/services/mail/mail.go @@ -4,7 +4,7 @@ import ( "bytes" "fmt" "io/fs" - "log" + "log/slog" "path" "sync" "text/template" @@ -21,27 +21,38 @@ const ( DefaultEmailTemplatePath string = "./email_templates" ) -func NewService(ess model.EmailServiceSettings, fs fs.FS, updIntrv time.Duration, templatesPath string) (model.EmailService, error) { +func NewService( + logger *slog.Logger, + ess model.EmailServiceSettings, + fs fs.FS, + updIntrv time.Duration, + templatesPath string, +) (model.EmailService, error) { var t model.EmailTransport switch ess.Type { case model.EmailServiceMailgun: t = mailgun.NewTransport(ess.Mailgun) case model.EmailServiceAWS: - tt, err := ses.NewTransport(ess.SES) + tt, err := ses.NewTransport(logger, ess.SES) if err != nil { return nil, err } t = tt case model.EmailServiceMock: - t = mock.NewTransport() + t = mock.NewTransport(logger) default: - return nil, fmt.Errorf("Email service of type '%s' is not supported", ess.Type) + return nil, fmt.Errorf("email service of type '%s' is not supported", ess.Type) } - watcher := storage.NewFSWatcher(fs, []string{}, updIntrv) + watcher := storage.NewFSWatcher( + logger, + fs, + []string{}, + updIntrv) return &EmailService{ + logger: logger, cache: sync.Map{}, transport: t, fs: fs, @@ -51,6 +62,7 @@ func NewService(ess model.EmailServiceSettings, fs fs.FS, updIntrv time.Duration } type EmailService struct { + logger *slog.Logger transport model.EmailTransport fs fs.FS cache sync.Map @@ -115,7 +127,9 @@ func (es *EmailService) watch() { for files := range es.watcher.WatchChan() { for _, f := range files { es.cache.Delete(f) - log.Printf("email template changed, the email template cache has been invalidated: %v", f) + + es.logger.Info("email template changed, the email template cache has been invalidated", + "file", f) } } } diff --git a/services/mail/mail_test.go b/services/mail/mail_test.go index 98097c25..11963e07 100644 --- a/services/mail/mail_test.go +++ b/services/mail/mail_test.go @@ -6,6 +6,7 @@ import ( "testing" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/services/mail" "github.com/spf13/afero" @@ -23,7 +24,7 @@ func TestEmailService_SendMessage(t *testing.T) { } afs := createFS() - service, err := mail.NewService(sts, afero.NewIOFS(afs), time.Second, "templates") + service, err := mail.NewService(logging.DefaultLogger, sts, afero.NewIOFS(afs), time.Second, "templates") require.NoError(t, err) service.Start() service.SendTemplateEmail( diff --git a/services/mail/mock/mock.go b/services/mail/mock/mock.go index 3c826414..ffdbf522 100644 --- a/services/mail/mock/mock.go +++ b/services/mail/mock/mock.go @@ -2,35 +2,47 @@ package mock import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" ) type EmailService struct { - SendMessages []string + logger *slog.Logger + sendMessages []string } // NewTransport creates new email mock transport, all it does just prints everything to console. -func NewTransport() model.EmailTransport { - return &EmailService{} +func NewTransport(logger *slog.Logger) model.EmailTransport { + return &EmailService{logger: logger} } // SendMessage returns nil error. func (es *EmailService) SendMessage(subject, body, recipient string) error { msg := fmt.Sprintf("โœ‰๏ธ: MOCK EMAIL SERVICE: Sending message \nsubject: %s\nbody: %s\n recipient: %s\n\n", subject, body, recipient) - fmt.Print(msg) - es.SendMessages = append(es.SendMessages, msg) + + es.logger.Debug("โœ‰๏ธ: MOCK EMAIL SERVICE: Sending message", + "subject", subject, + "body", body, + "recipient", recipient) + + es.sendMessages = append(es.sendMessages, msg) return nil } // SendHTML returns nil error. func (es *EmailService) SendHTML(subject, html, recipient string) error { msg := fmt.Sprintf("โœ‰๏ธ: MOCK EMAIL SERVICE: Sending HTML \nsubject: %s\nhtml: %s\n recipient: %s\n\n", subject, html, recipient) - fmt.Print(msg) - es.SendMessages = append(es.SendMessages, msg) + + es.logger.Debug("โœ‰๏ธ: MOCK EMAIL SERVICE: Sending HTML", + "subject", subject, + "html", html, + "recipient", recipient) + + es.sendMessages = append(es.sendMessages, msg) return nil } func (es *EmailService) Messages() []string { - return es.SendMessages + return es.sendMessages } diff --git a/services/mail/ses/ses.go b/services/mail/ses/ses.go index feb783a3..58d4f1f8 100644 --- a/services/mail/ses/ses.go +++ b/services/mail/ses/ses.go @@ -1,17 +1,21 @@ package ses import ( - "log" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/aws/awserr" "github.com/aws/aws-sdk-go/aws/session" "github.com/aws/aws-sdk-go/service/ses" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) // NewTransport creates AWS SES email service. -func NewTransport(ess model.SESEmailServiceSettings) (model.EmailTransport, error) { +func NewTransport( + logger *slog.Logger, + ess model.SESEmailServiceSettings, +) (model.EmailTransport, error) { sess, err := session.NewSession(&aws.Config{ Region: aws.String(ess.Region), }, @@ -20,11 +24,16 @@ func NewTransport(ess model.SESEmailServiceSettings) (model.EmailTransport, erro return nil, err } - return &transport{Sender: ess.Sender, service: ses.New(sess)}, nil + return &transport{ + logger: logger, + Sender: ess.Sender, + service: ses.New(sess), + }, nil } // EmailService sends email with Amazon Simple Email Service. type transport struct { + logger *slog.Logger Sender string service *ses.SES } @@ -53,7 +62,7 @@ func (es *transport) SendMessage(subject, body, recipient string) error { Source: aws.String(es.Sender), } _, err := es.service.SendEmail(input) - logAWSError(err) + es.logAWSError(err) return err } @@ -81,29 +90,23 @@ func (es *transport) SendHTML(subject, html, recipient string) error { Source: aws.String(es.Sender), } _, err := es.service.SendEmail(input) - logAWSError(err) + es.logAWSError(err) return err } -func logAWSError(err error) { +func (es *transport) logAWSError(err error) { if err == nil { return } aerr, ok := err.(awserr.Error) if !ok { - log.Println("Could not cast the error to AWS error:", err) + es.logger.Error("Could not cast the error to AWS error", + logging.FieldError, err) return } - switch aerr.Code() { - case ses.ErrCodeMessageRejected: - log.Println(ses.ErrCodeMessageRejected, aerr.Error()) - case ses.ErrCodeMailFromDomainNotVerifiedException: - log.Println(ses.ErrCodeMailFromDomainNotVerifiedException, aerr.Error()) - case ses.ErrCodeConfigurationSetDoesNotExistException: - log.Println(ses.ErrCodeConfigurationSetDoesNotExistException, aerr.Error()) - default: - log.Println(aerr.Error()) - } + es.logger.Error("aws error", + "code", aerr.Code(), + logging.FieldError, aerr.Error()) } diff --git a/services/sms/mock/mock.go b/services/sms/mock/mock.go index 3f7a2806..cd7e2d92 100644 --- a/services/sms/mock/mock.go +++ b/services/sms/mock/mock.go @@ -1,17 +1,23 @@ package mock -import "fmt" +import ( + "log/slog" +) // SMSServiceMock mocks SMS service. -type SMSServiceMock struct{} +type SMSServiceMock struct { + logger *slog.Logger +} // NewSMSService returns pointer to newly created SMS service mock. -func NewSMSService() (*SMSServiceMock, error) { - return &SMSServiceMock{}, nil +func NewSMSService(logger *slog.Logger) (*SMSServiceMock, error) { + return &SMSServiceMock{logger}, nil } // SendSMS implements SMSService. func (ss *SMSServiceMock) SendSMS(recipient, message string) error { - fmt.Printf("๐Ÿ“ฑ: MOCK SMS SERVICE: Sending SMS: \nrecipient: %s\nmessage: %s\n\n", recipient, message) + ss.logger.Info("๐Ÿ“ฑ: MOCK SMS SERVICE: Sending SMS", + "recipient", recipient, + "message", message) return nil } diff --git a/services/sms/sms.go b/services/sms/sms.go index 2dbfe12f..f6188a43 100644 --- a/services/sms/sms.go +++ b/services/sms/sms.go @@ -2,6 +2,7 @@ package sms import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/services/sms/mock" @@ -10,16 +11,19 @@ import ( "github.com/madappgang/identifo/v2/services/sms/twilio" ) -func NewService(settings model.SMSServiceSettings) (model.SMSService, error) { +func NewService( + logger *slog.Logger, + settings model.SMSServiceSettings, +) (model.SMSService, error) { switch settings.Type { case model.SMSServiceTwilio: - return twilio.NewSMSService(settings.Twilio) + return twilio.NewSMSService(logger, settings.Twilio) case model.SMSServiceNexmo: return nexmo.NewSMSService(settings.Nexmo) case model.SMSServiceRouteMobile: return routemobile.NewSMSService(settings.Routemobile) case model.SMSServiceMock: - return mock.NewSMSService() + return mock.NewSMSService(logger) } return nil, fmt.Errorf("SMS service of type '%s' is not supported", settings.Type) } diff --git a/services/sms/sms_test.go b/services/sms/sms_test.go index fd156452..b96a4416 100644 --- a/services/sms/sms_test.go +++ b/services/sms/sms_test.go @@ -4,6 +4,7 @@ import ( "fmt" "testing" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/services/sms" "github.com/madappgang/identifo/v2/services/sms/twilio" @@ -21,7 +22,7 @@ func TestTwilioSMSCreate(t *testing.T) { }, } - service, err := sms.NewService(settings) + service, err := sms.NewService(logging.DefaultLogger, settings) require.NoError(t, err) assert.IsType(t, &twilio.SMSService{}, service) diff --git a/services/sms/twilio/twilio.go b/services/sms/twilio/twilio.go index 81743f23..c4144b94 100644 --- a/services/sms/twilio/twilio.go +++ b/services/sms/twilio/twilio.go @@ -2,7 +2,7 @@ package twilio import ( "errors" - "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/twilio/twilio-go" @@ -11,14 +11,19 @@ import ( // SMSService sends SMS via Twilio service. type SMSService struct { + logger *slog.Logger messagingServiceSid string sendFrom string client *twilio.RestClient } // NewSMSService creates, inits and returns Twilio-backed SMS service. -func NewSMSService(settings model.TwilioServiceSettings) (*SMSService, error) { +func NewSMSService( + logger *slog.Logger, + settings model.TwilioServiceSettings, +) (*SMSService, error) { t := &SMSService{ + logger: logger, messagingServiceSid: settings.ServiceSid, sendFrom: settings.SendFrom, client: twilio.NewRestClientWithParams(twilio.ClientParams{ @@ -39,7 +44,7 @@ func NewSMSService(settings model.TwilioServiceSettings) (*SMSService, error) { // SendSMS sends SMS messages using Twilio service. func (ss *SMSService) SendSMS(recipient, message string) error { if ss.client == nil { - return errors.New("Twilio SMS service is not configured") + return errors.New("twilio SMS service is not configured") } params := &twilioApi.CreateMessageParams{} params.SetTo(recipient) @@ -54,13 +59,14 @@ func (ss *SMSService) SendSMS(recipient, message string) error { if len(ss.messagingServiceSid) > 0 { params.SetMessagingServiceSid(ss.messagingServiceSid) } else { - return errors.New("Twilio SMS service has no sendFrom nor messagingServiceSid for sending the message configured") + return errors.New("twilio SMS service has no sendFrom nor messagingServiceSid for sending the message configured") } resp, err := ss.client.Api.CreateMessage(params) if err != nil { return err } - fmt.Printf("Twilio service sending SMS %+v\n", resp) + ss.logger.Info("Twilio service sending SMS", + "response", resp) return nil } diff --git a/storage/app.go b/storage/app.go index c67107c5..cae1f69e 100644 --- a/storage/app.go +++ b/storage/app.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -11,19 +12,21 @@ import ( ) // NewAppStorage creates new app storage from settings -func NewAppStorage(settings model.DatabaseSettings) (model.AppStorage, error) { +func NewAppStorage( + logger *slog.Logger, + settings model.DatabaseSettings) (model.AppStorage, error) { switch settings.Type { case model.DBTypeBoltDB: - return boltdb.NewAppStorage(settings.BoltDB) + return boltdb.NewAppStorage(logger, settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewAppStorage(settings.Mongo) + return mongo.NewAppStorage(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewAppStorage(settings.Dynamo) + return dynamodb.NewAppStorage(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: - return mem.NewAppStorage() + return mem.NewAppStorage(logger) default: - return nil, fmt.Errorf("App storage type is not supported") + return nil, fmt.Errorf("app storage type is not supported") } } diff --git a/storage/boltdb/app.go b/storage/boltdb/app.go index 83c2c8c1..4752eb2a 100644 --- a/storage/boltdb/app.go +++ b/storage/boltdb/app.go @@ -3,9 +3,10 @@ package boltdb import ( "encoding/json" "fmt" - "log" + "log/slog" "strings" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" bolt "go.etcd.io/bbolt" @@ -17,7 +18,9 @@ const ( ) // NewAppStorage creates new BoltDB AppStorage implementation. -func NewAppStorage(settings model.BoltDBDatabaseSettings) (model.AppStorage, error) { +func NewAppStorage( + logger *slog.Logger, + settings model.BoltDBDatabaseSettings) (model.AppStorage, error) { if len(settings.Path) == 0 { return nil, fmt.Errorf("unable to find init boltdb storage with empty database path") } @@ -28,7 +31,10 @@ func NewAppStorage(settings model.BoltDBDatabaseSettings) (model.AppStorage, err return nil, err } - as := AppStorage{db: db} + as := AppStorage{ + logger: logger, + db: db, + } // ensure we have app's bucket in the database if err := db.Update(func(tx *bolt.Tx) error { if _, err := tx.CreateBucketIfNotExists([]byte(AppBucket)); err != nil { @@ -43,7 +49,8 @@ func NewAppStorage(settings model.BoltDBDatabaseSettings) (model.AppStorage, err // AppStorage is a fully functional app storage. type AppStorage struct { - db *bolt.DB + logger *slog.Logger + db *bolt.DB } // AppByID returns app from memory by ID. @@ -199,7 +206,8 @@ func (as *AppStorage) ImportJSON(data []byte, cleanOldData bool) error { apd := []model.AppData{} if err := json.Unmarshal(data, &apd); err != nil { - log.Println(err) + as.logger.Error("unmarshalling app data", + logging.FieldError, err) return err } for _, a := range apd { @@ -213,6 +221,6 @@ func (as *AppStorage) ImportJSON(data []byte, cleanOldData bool) error { // Close closes underlying database. func (as *AppStorage) Close() { if err := CloseDB(as.db); err != nil { - log.Printf("Error closing app storage: %s\n", err) + as.logger.Error("Error closing app storage", logging.FieldError, err) } } diff --git a/storage/boltdb/app_test.go b/storage/boltdb/app_test.go index 13eef910..52cf39ec 100644 --- a/storage/boltdb/app_test.go +++ b/storage/boltdb/app_test.go @@ -5,6 +5,7 @@ import ( "path/filepath" "testing" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" "github.com/stretchr/testify/assert" @@ -40,7 +41,7 @@ func TestBoltDBAppCreateApp(t *testing.T) { sts := model.BoltDBDatabaseSettings{ Path: dbpath, } - apps, err := boltdb.NewAppStorage(sts) + apps, err := boltdb.NewAppStorage(logging.DefaultLogger, sts) require.NoError(t, err) defer apps.Close() @@ -64,7 +65,7 @@ func TestBoltDBAppFindAppById(t *testing.T) { sts := model.BoltDBDatabaseSettings{ Path: dbpath, } - apps, err := boltdb.NewAppStorage(sts) + apps, err := boltdb.NewAppStorage(logging.DefaultLogger, sts) require.NoError(t, err) defer apps.Close() @@ -87,7 +88,7 @@ func TestBoltDBAppFindAppFetchApps(t *testing.T) { sts := model.BoltDBDatabaseSettings{ Path: dbpath, } - apps, err := boltdb.NewAppStorage(sts) + apps, err := boltdb.NewAppStorage(logging.DefaultLogger, sts) require.NoError(t, err) defer apps.Close() diff --git a/storage/boltdb/invite.go b/storage/boltdb/invite.go index 7e8c402e..aa024639 100644 --- a/storage/boltdb/invite.go +++ b/storage/boltdb/invite.go @@ -3,11 +3,12 @@ package boltdb import ( "encoding/json" "fmt" - "log" + "log/slog" "time" bolt "go.etcd.io/bbolt" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" ) @@ -19,11 +20,15 @@ const ( // InviteStorage is a BoltDB invite storage. type InviteStorage struct { - db *bolt.DB + logger *slog.Logger + db *bolt.DB } // NewInviteStorage creates a BoltDB invites storage. -func NewInviteStorage(settings model.BoltDBDatabaseSettings) (model.InviteStorage, error) { +func NewInviteStorage( + logger *slog.Logger, + settings model.BoltDBDatabaseSettings, +) (model.InviteStorage, error) { if len(settings.Path) == 0 { return nil, ErrorEmptyDatabasePath } @@ -34,11 +39,14 @@ func NewInviteStorage(settings model.BoltDBDatabaseSettings) (model.InviteStorag return nil, err } - is := &InviteStorage{db: db} + is := &InviteStorage{ + logger: logger, + db: db, + } // Ensure that we have needed bucket in the database. if err := db.Update(func(tx *bolt.Tx) error { if _, err := tx.CreateBucketIfNotExists([]byte(InviteBucket)); err != nil { - return fmt.Errorf("create bucket: %s", err) + return fmt.Errorf("create bucket: %w", err) } return nil }); err != nil { @@ -50,7 +58,6 @@ func NewInviteStorage(settings model.BoltDBDatabaseSettings) (model.InviteStorag // Save creates and saves new invite to a database. func (is *InviteStorage) Save(email, inviteToken, role, appID, createdBy string, expiresAt time.Time) error { return is.db.Update(func(tx *bolt.Tx) error { - fmt.Println(expiresAt) ib := tx.Bucket([]byte(InviteBucket)) invite := model.Invite{ @@ -226,6 +233,6 @@ func (is *InviteStorage) ArchiveByID(id string) error { // Close closes underlying database. func (is *InviteStorage) Close() { if err := CloseDB(is.db); err != nil { - log.Printf("Error closing invite storage: %s\n", err) + is.logger.Error("Error closing invite storage", logging.FieldError, err) } } diff --git a/storage/boltdb/token.go b/storage/boltdb/token.go index 34de7b7f..09c94a70 100644 --- a/storage/boltdb/token.go +++ b/storage/boltdb/token.go @@ -2,8 +2,9 @@ package boltdb import ( "fmt" - "log" + "log/slog" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" bolt "go.etcd.io/bbolt" ) @@ -14,7 +15,10 @@ const ( ) // NewTokenStorage creates a BoltDB token storage. -func NewTokenStorage(settings model.BoltDBDatabaseSettings) (model.TokenStorage, error) { +func NewTokenStorage( + logger *slog.Logger, + settings model.BoltDBDatabaseSettings, +) (model.TokenStorage, error) { if len(settings.Path) == 0 { return nil, ErrorEmptyDatabasePath } @@ -25,7 +29,10 @@ func NewTokenStorage(settings model.BoltDBDatabaseSettings) (model.TokenStorage, return nil, err } - ts := &TokenStorage{db: db} + ts := &TokenStorage{ + logger: logger, + db: db, + } // Ensure that we have needed bucket in the database. if err := db.Update(func(tx *bolt.Tx) error { if _, err := tx.CreateBucketIfNotExists([]byte(TokenBucket)); err != nil { @@ -40,7 +47,8 @@ func NewTokenStorage(settings model.BoltDBDatabaseSettings) (model.TokenStorage, // TokenStorage is a BoltDB token storage. type TokenStorage struct { - db *bolt.DB + logger *slog.Logger + db *bolt.DB } // SaveToken saves token in the storage. @@ -79,6 +87,6 @@ func (ts *TokenStorage) DeleteToken(token string) error { // Close closes underlying database. func (ts *TokenStorage) Close() { if err := CloseDB(ts.db); err != nil { - log.Printf("Error closing token storage: %s\n", err) + ts.logger.Error("Error closing token storage", logging.FieldError, err) } } diff --git a/storage/boltdb/token_blocklist.go b/storage/boltdb/token_blocklist.go index cc3fefa5..ba16fe95 100644 --- a/storage/boltdb/token_blocklist.go +++ b/storage/boltdb/token_blocklist.go @@ -2,8 +2,9 @@ package boltdb import ( "fmt" - "log" + "log/slog" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" bolt "go.etcd.io/bbolt" ) @@ -14,7 +15,9 @@ const ( ) // NewTokenBlacklist creates a token blacklist in BoltDB. -func NewTokenBlacklist(settings model.BoltDBDatabaseSettings) (model.TokenBlacklist, error) { +func NewTokenBlacklist( + logger *slog.Logger, + settings model.BoltDBDatabaseSettings) (model.TokenBlacklist, error) { if len(settings.Path) == 0 { return nil, ErrorEmptyDatabasePath } @@ -25,7 +28,10 @@ func NewTokenBlacklist(settings model.BoltDBDatabaseSettings) (model.TokenBlackl return nil, err } - tb := &TokenBlacklist{db: db} + tb := &TokenBlacklist{ + logger: logger, + db: db, + } if err := tb.db.Update(func(tx *bolt.Tx) error { if _, err := tx.CreateBucketIfNotExists([]byte(BlacklistedTokenBucket)); err != nil { return fmt.Errorf("create bucket: %s", err) @@ -39,7 +45,8 @@ func NewTokenBlacklist(settings model.BoltDBDatabaseSettings) (model.TokenBlackl // TokenBlacklist is a BoltDB token blacklist. type TokenBlacklist struct { - db *bolt.DB + logger *slog.Logger + db *bolt.DB } // Add adds token in the blacklist. @@ -68,6 +75,6 @@ func (tb *TokenBlacklist) IsBlacklisted(token string) bool { // Close closes underlying database. func (tb *TokenBlacklist) Close() { if err := CloseDB(tb.db); err != nil { - log.Printf("Error closing token blacklist storage: %s\n", err) + tb.logger.Error("error closing token blacklist storage", logging.FieldError, err) } } diff --git a/storage/boltdb/user.go b/storage/boltdb/user.go index d455f78e..f8e1e400 100644 --- a/storage/boltdb/user.go +++ b/storage/boltdb/user.go @@ -4,10 +4,11 @@ import ( "encoding/json" "errors" "fmt" - "log" + "log/slog" "strings" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" bolt "go.etcd.io/bbolt" @@ -23,7 +24,10 @@ const ( ) // NewUserStorage creates and inits an embedded user storage. -func NewUserStorage(settings model.BoltDBDatabaseSettings) (model.UserStorage, error) { +func NewUserStorage( + logger *slog.Logger, + settings model.BoltDBDatabaseSettings, +) (model.UserStorage, error) { if len(settings.Path) == 0 { return nil, ErrorEmptyDatabasePath } @@ -34,7 +38,10 @@ func NewUserStorage(settings model.BoltDBDatabaseSettings) (model.UserStorage, e return nil, err } - us := UserStorage{db: db} + us := UserStorage{ + logger: logger, + db: db, + } if err := us.createBuckets(); err != nil { return nil, err @@ -45,7 +52,8 @@ func NewUserStorage(settings model.BoltDBDatabaseSettings) (model.UserStorage, e // UserStorage implements user storage interface for BoltDB. type UserStorage struct { - db *bolt.DB + logger *slog.Logger + db *bolt.DB } func (us *UserStorage) createBuckets() error { @@ -514,21 +522,24 @@ func (us *UserStorage) ImportJSON(data []byte, clearOldData bool) error { func (us *UserStorage) UpdateLoginMetadata(userID string) { user, err := us.UserByID(userID) if err != nil { - log.Printf("Cannot get user by ID %s: %s\n", userID, err) + us.logger.Error("Cannot get user by ID", + logging.FieldUserID, userID, + logging.FieldError, err) + return } user.NumOfLogins++ user.LatestLoginTime = time.Now().Unix() - if _, err := us.UpdateUser(UserBucket, user); err != nil { - log.Println("Cannot update user login info: ", err) + if _, err := us.UpdateUser(userID, user); err != nil { + us.logger.Error("Cannot update user login info", logging.FieldError, err) } } // Close closes underlying database. func (us *UserStorage) Close() { if err := CloseDB(us.db); err != nil { - log.Printf("Error closing user storage: %s\n", err) + us.logger.Error("Error closing user storage", logging.FieldError, err) } } diff --git a/storage/boltdb/verification_code.go b/storage/boltdb/verification_code.go index e8e30c39..c4f66e0d 100644 --- a/storage/boltdb/verification_code.go +++ b/storage/boltdb/verification_code.go @@ -2,8 +2,9 @@ package boltdb import ( "fmt" - "log" + "log/slog" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" bolt "go.etcd.io/bbolt" ) @@ -14,7 +15,10 @@ const ( ) // NewVerificationCodeStorage creates and inits BoltDB verification code storage. -func NewVerificationCodeStorage(settings model.BoltDBDatabaseSettings) (model.VerificationCodeStorage, error) { +func NewVerificationCodeStorage( + logger *slog.Logger, + settings model.BoltDBDatabaseSettings, +) (model.VerificationCodeStorage, error) { if len(settings.Path) == 0 { return nil, ErrorEmptyDatabasePath } @@ -25,7 +29,10 @@ func NewVerificationCodeStorage(settings model.BoltDBDatabaseSettings) (model.Ve return nil, err } - vcs := &VerificationCodeStorage{db: db} + vcs := &VerificationCodeStorage{ + logger: logger, + db: db, + } if err := db.Update(func(tx *bolt.Tx) error { if _, err := tx.CreateBucketIfNotExists([]byte(VerificationCodesBucket)); err != nil { @@ -41,7 +48,8 @@ func NewVerificationCodeStorage(settings model.BoltDBDatabaseSettings) (model.Ve // VerificationCodeStorage implements verification code storage interface. type VerificationCodeStorage struct { - db *bolt.DB + logger *slog.Logger + db *bolt.DB } // IsVerificationCodeFound checks whether verification code can be found. @@ -79,6 +87,6 @@ func (vcs *VerificationCodeStorage) CreateVerificationCode(phone, code string) e // Close closes underlying database. func (vcs *VerificationCodeStorage) Close() { if err := CloseDB(vcs.db); err != nil { - log.Printf("Error closing verification code storage: %s\n", err) + vcs.logger.Error("Error closing verification code storage", logging.FieldError, err) } } diff --git a/storage/dynamodb/app.go b/storage/dynamodb/app.go index f05528b4..43cbfa4f 100644 --- a/storage/dynamodb/app.go +++ b/storage/dynamodb/app.go @@ -2,11 +2,12 @@ package dynamodb import ( "encoding/json" - "log" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" ) @@ -14,7 +15,10 @@ import ( var appsTableName = "Applications" // NewAppStorage creates new DynamoDB AppStorage implementation. -func NewAppStorage(settings model.DynamoDatabaseSettings) (model.AppStorage, error) { +func NewAppStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.AppStorage, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -25,21 +29,24 @@ func NewAppStorage(settings model.DynamoDatabaseSettings) (model.AppStorage, err return nil, err } - as := &AppStorage{db: db} + as := &AppStorage{ + logger: logger, + db: db, + } err = as.ensureTable() return as, err } // AppStorage a is fully functional app storage. type AppStorage struct { - db *DB + logger *slog.Logger + db *DB } // ensureTable ensures that app table exists in database. func (as *AppStorage) ensureTable() error { exists, err := as.db.IsTableExists(appsTableName) if err != nil { - log.Println("Error checking Applications table existence:", err) return err } if exists { @@ -82,7 +89,7 @@ func (as *AppStorage) AppByID(id string) (model.AppData, error) { }, }) if err != nil { - log.Println("Error getting application:", err) + as.logger.Error("Error getting application", logging.FieldError, err) return model.AppData{}, ErrorInternalError } @@ -92,7 +99,7 @@ func (as *AppStorage) AppByID(id string) (model.AppData, error) { appdata := model.AppData{} if err = dynamodbattribute.UnmarshalMap(result.Item, &appdata); err != nil { - log.Println("Error unmarshalling app data:", err) + as.logger.Error("Error unmarshalling app data", logging.FieldError, err) return model.AppData{}, ErrorInternalError } return appdata, nil @@ -125,7 +132,7 @@ func (as *AppStorage) CreateApp(app model.AppData) (model.AppData, error) { av, err := dynamodbattribute.MarshalMap(app) if err != nil { - log.Println("error marshalling app: ", err) + as.logger.Error("error marshalling app", logging.FieldError, err) return model.AppData{}, ErrorInternalError } @@ -135,7 +142,7 @@ func (as *AppStorage) CreateApp(app model.AppData) (model.AppData, error) { } if _, err = as.db.C.PutItem(input); err != nil { - log.Println("error putting app to storage: ", err) + as.logger.Error("error putting app to storage", logging.FieldError, err) return model.AppData{}, ErrorInternalError } return app, nil @@ -144,7 +151,7 @@ func (as *AppStorage) CreateApp(app model.AppData) (model.AppData, error) { // DisableApp disables app in DynamoDB storage. func (as *AppStorage) DisableApp(app model.AppData) error { if _, err := xid.FromString(app.ID); err != nil { - log.Println("incorrect AppID: ", app.ID) + as.logger.Warn("incorrect AppID", logging.FieldAppID, app.ID) return model.ErrorWrongDataFormat } input := &dynamodb.UpdateItemInput{ @@ -164,7 +171,7 @@ func (as *AppStorage) DisableApp(app model.AppData) error { } if _, err := as.db.C.UpdateItem(input); err != nil { - log.Println("Error updating app:", err) + as.logger.Error("Error updating app", logging.FieldError, err) return ErrorInternalError } return nil @@ -173,7 +180,7 @@ func (as *AppStorage) DisableApp(app model.AppData) error { // UpdateApp updates app in DynamoDB storage. func (as *AppStorage) UpdateApp(appID string, app model.AppData) (model.AppData, error) { if _, err := xid.FromString(appID); err != nil { - log.Println("incorrect appID: ", appID) + as.logger.Warn("incorrect AppID", logging.FieldAppID, app.ID) return model.AppData{}, model.ErrorWrongDataFormat } @@ -184,7 +191,7 @@ func (as *AppStorage) UpdateApp(appID string, app model.AppData) (model.AppData, oldAppData := model.AppData{ID: appID} if err := as.DisableApp(oldAppData); err != nil { - log.Println("Error disabling old app:", err) + as.logger.Error("Error disabling old app:", logging.FieldError, err) return model.AppData{}, err } @@ -192,8 +199,6 @@ func (as *AppStorage) UpdateApp(appID string, app model.AppData) (model.AppData, return updatedApp, err } -const maxAppsLimit = 20 - // FetchApps fetches apps which name satisfies provided filterString. // Supports pagination. Search is case-sensitive for now. func (as *AppStorage) FetchApps(filterString string) ([]model.AppData, error) { @@ -213,7 +218,7 @@ func (as *AppStorage) FetchApps(filterString string) ([]model.AppData, error) { result, err := as.db.C.Scan(scanInput) if err != nil { - log.Println("Error querying for apps:", err) + as.logger.Error("Error querying for apps", logging.FieldError, err) return []model.AppData{}, ErrorInternalError } @@ -221,7 +226,7 @@ func (as *AppStorage) FetchApps(filterString string) ([]model.AppData, error) { for i := 0; i < len(result.Items); i++ { appData := model.AppData{} if err = dynamodbattribute.UnmarshalMap(result.Items[i], &appData); err != nil { - log.Println("error while unmarshal app: ", err) + as.logger.Error("error while unmarshal app", logging.FieldError, err) return []model.AppData{}, ErrorInternalError } apps[i] = appData @@ -258,7 +263,7 @@ func (as *AppStorage) ImportJSON(data []byte, cleanOldData bool) error { } apd := []model.AppData{} if err := json.Unmarshal(data, &apd); err != nil { - log.Println("error while unmarshal app data: ", err) + as.logger.Error("Error while unmarshal app data", logging.FieldError, err) return err } for _, a := range apd { diff --git a/storage/dynamodb/db.go b/storage/dynamodb/db.go index f1dd69ba..a6eab32c 100644 --- a/storage/dynamodb/db.go +++ b/storage/dynamodb/db.go @@ -2,7 +2,6 @@ package dynamodb import ( "context" - "log" "time" "github.com/aws/aws-sdk-go/aws" @@ -19,7 +18,6 @@ func NewDB(endpoint string, region string) (*DB, error) { } sess, err := session.NewSession(config) if err != nil { - log.Println(err) return nil, err } @@ -46,7 +44,6 @@ func (db *DB) IsTableExists(table string) (bool, error) { // if table not exists - create table } if err != nil { - log.Println(err) return false, err } diff --git a/storage/dynamodb/invite.go b/storage/dynamodb/invite.go index bffcf61e..62342a97 100644 --- a/storage/dynamodb/invite.go +++ b/storage/dynamodb/invite.go @@ -1,12 +1,13 @@ package dynamodb import ( - "log" + "log/slog" "time" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" ) @@ -24,11 +25,15 @@ type inviteIndexByEmailData struct { // InviteStorage is a DynamoDB invite storage. type InviteStorage struct { - db *DB + logger *slog.Logger + db *DB } // NewInviteStorage creates new DynamoDB invite storage. -func NewInviteStorage(settings model.DynamoDatabaseSettings) (model.InviteStorage, error) { +func NewInviteStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.InviteStorage, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -39,7 +44,10 @@ func NewInviteStorage(settings model.DynamoDatabaseSettings) (model.InviteStorag return nil, err } - is := &InviteStorage{db: db} + is := &InviteStorage{ + logger: logger, + db: db, + } err = is.ensureTable() return is, err } @@ -48,7 +56,7 @@ func NewInviteStorage(settings model.DynamoDatabaseSettings) (model.InviteStorag func (is *InviteStorage) ensureTable() error { exists, err := is.db.IsTableExists(invitesTableName) if err != nil { - log.Println("Error checking Invites table existence:", err) + is.logger.Error("Error checking Invites table existence", logging.FieldError, err) return err } if exists { @@ -110,7 +118,7 @@ func (is *InviteStorage) Save(email, inviteToken, role, appID, createdBy string, iv, err := dynamodbattribute.MarshalMap(invite) if err != nil { - log.Println("error marshalling invite: ", err) + is.logger.Error("Error marshalling invite", logging.FieldError, err) return ErrorInternalError } @@ -120,7 +128,7 @@ func (is *InviteStorage) Save(email, inviteToken, role, appID, createdBy string, } if _, err = is.db.C.PutItem(input); err != nil { - log.Println("error putting invite to storage: ", err) + is.logger.Error("Error putting invite to storage", logging.FieldError, err) return ErrorInternalError } return nil @@ -138,7 +146,7 @@ func (is *InviteStorage) inviteIdxByEmail(email string) (*inviteIndexByEmailData Select: aws.String("ALL_PROJECTED_ATTRIBUTES"), }) if err != nil { - log.Println("error querying for invite by email: ", err) + is.logger.Error("Error querying for invite by email", logging.FieldError, err) return nil, ErrorInternalError } if len(result.Items) == 0 { @@ -148,7 +156,7 @@ func (is *InviteStorage) inviteIdxByEmail(email string) (*inviteIndexByEmailData item := result.Items[0] inviteData := new(inviteIndexByEmailData) if err = dynamodbattribute.UnmarshalMap(item, inviteData); err != nil { - log.Println("error while unmarshal invite: ", err) + is.logger.Error("Error while unmarshal invite", logging.FieldError, err) return nil, ErrorInternalError } return inviteData, nil @@ -158,13 +166,13 @@ func (is *InviteStorage) inviteIdxByEmail(email string) (*inviteIndexByEmailData func (is *InviteStorage) GetByEmail(email string) (model.Invite, error) { inviteIdx, err := is.inviteIdxByEmail(email) if err != nil { - log.Println("error getting invite by email: ", err) + is.logger.Error("Error getting invite by email", logging.FieldError, err) return model.Invite{}, err } invite, err := is.GetByID(inviteIdx.ID) if err != nil { - log.Println("error querying invite by id: ", err) + is.logger.Error("Error querying invite by id", logging.FieldError, err) return model.Invite{}, ErrorInternalError } @@ -186,7 +194,7 @@ func (is *InviteStorage) GetByID(id string) (model.Invite, error) { }, }) if err != nil { - log.Println("Error getting invite:", err) + is.logger.Error("Error getting invite", logging.FieldError, err) return model.Invite{}, ErrorInternalError } @@ -196,7 +204,7 @@ func (is *InviteStorage) GetByID(id string) (model.Invite, error) { invite := model.Invite{} if err = dynamodbattribute.UnmarshalMap(result.Item, &invite); err != nil { - log.Println("Error unmarshalling invite:", err) + is.logger.Error("Error unmarshalling invite", logging.FieldError, err) return model.Invite{}, ErrorInternalError } return invite, nil @@ -226,7 +234,7 @@ func (is *InviteStorage) GetAll(withArchived bool, skip, limit int) ([]model.Inv result, err := is.db.C.Scan(scanInput) if err != nil { - log.Println("Error querying for invites:", err) + is.logger.Error("Error querying for invites", logging.FieldError, err) return []model.Invite{}, 0, ErrorInternalError } @@ -237,7 +245,7 @@ func (is *InviteStorage) GetAll(withArchived bool, skip, limit int) ([]model.Inv } invite := model.Invite{} if err = dynamodbattribute.UnmarshalMap(result.Items[i], &invite); err != nil { - log.Println("error while unmarshal invite: ", err) + is.logger.Error("error while unmarshal invite", logging.FieldError, err) return []model.Invite{}, 0, ErrorInternalError } invites[i] = invite @@ -260,17 +268,17 @@ func (is *InviteStorage) ArchiveAllByEmail(email string) error { result, err := is.db.C.Scan(scanInput) if err != nil { - log.Println("Error querying for invites:", err) + is.logger.Error("Error querying for invites:", err) return ErrorInternalError } for i := 0; i < len(result.Items); i++ { invite := model.Invite{} if err = dynamodbattribute.UnmarshalMap(result.Items[i], &invite); err != nil { - log.Println("error while unmarshal invite: ", err) + is.logger.Error("Error while unmarshal invite", err) } if err := is.ArchiveByID(invite.ID); err != nil { - log.Printf("error while ArchiveByID: %v", err) + is.logger.Error("Error while ArchiveByID", logging.FieldError, err) } } return nil @@ -279,7 +287,7 @@ func (is *InviteStorage) ArchiveAllByEmail(email string) error { // ArchiveByID archived specific invite by its ID. func (is *InviteStorage) ArchiveByID(id string) error { if _, err := xid.FromString(id); err != nil { - log.Println("incorrect invite id: ", id) + is.logger.Error("Incorrect invite id", "id", id) return model.ErrorWrongDataFormat } input := &dynamodb.UpdateItemInput{ @@ -299,7 +307,7 @@ func (is *InviteStorage) ArchiveByID(id string) error { } if _, err := is.db.C.UpdateItem(input); err != nil { - log.Printf("Error archiving %s invite: %v\n", id, err) + is.logger.Error("Error archiving invite", "id", id, logging.FieldError, err) return ErrorInternalError } return nil diff --git a/storage/dynamodb/management_keys.go b/storage/dynamodb/management_keys.go index 04d62460..d27dfe2d 100644 --- a/storage/dynamodb/management_keys.go +++ b/storage/dynamodb/management_keys.go @@ -3,10 +3,11 @@ package dynamodb import ( "context" "errors" - "log" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -15,7 +16,10 @@ const ( ) // NewManagementKeysStorage creates and provisions new management keys storage instance. -func NewManagementKeysStorage(settings model.DynamoDatabaseSettings) (model.ManagementKeysStorage, error) { +func NewManagementKeysStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.ManagementKeysStorage, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -26,14 +30,18 @@ func NewManagementKeysStorage(settings model.DynamoDatabaseSettings) (model.Mana return nil, err } - us := &ManagementKeysStorage{db: db} + us := &ManagementKeysStorage{ + logger: logger, + db: db, + } err = us.ensureTable() return us, err } // UserStorage stores and manages data in DynamoDB storage. type ManagementKeysStorage struct { - db *DB + logger *slog.Logger + db *DB } func (ms *ManagementKeysStorage) GetKey(ctx context.Context, id string) (model.ManagementKey, error) { @@ -69,7 +77,6 @@ func (ms *ManagementKeysStorage) GeyAllKeys(ctx context.Context) ([]model.Manage func (ms *ManagementKeysStorage) ensureTable() error { exists, err := ms.db.IsTableExists(managementKeyTableName) if err != nil { - log.Println("Error checking for table existence:", err) return err } if !exists { @@ -100,7 +107,7 @@ func (ms *ManagementKeysStorage) ensureTable() error { TableName: aws.String(managementKeyTableName), } if _, err = ms.db.C.CreateTable(input); err != nil { - log.Println("Error creating table:", err) + ms.logger.Error("Error creating table", logging.FieldError, err) return err } } diff --git a/storage/dynamodb/session.go b/storage/dynamodb/session.go index e503ee9a..9c65089f 100644 --- a/storage/dynamodb/session.go +++ b/storage/dynamodb/session.go @@ -2,7 +2,7 @@ package dynamodb import ( "fmt" - "log" + "log/slog" "time" "github.com/aws/aws-sdk-go/aws" @@ -10,6 +10,7 @@ import ( "github.com/aws/aws-sdk-go/aws/session" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -19,11 +20,15 @@ const ( // DynamoDBSessionStorage is a DynamoDB-backed storage for admin sessions. type DynamoDBSessionStorage struct { - db *dynamodb.DynamoDB + logger *slog.Logger + db *dynamodb.DynamoDB } // NewSessionStorage creates new DynamoDB session storage. -func NewSessionStorage(settings model.DynamoDatabaseSettings) (model.SessionStorage, error) { +func NewSessionStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.SessionStorage, error) { config := &aws.Config{ Region: aws.String(settings.Region), Endpoint: aws.String(settings.Endpoint), @@ -31,11 +36,13 @@ func NewSessionStorage(settings model.DynamoDatabaseSettings) (model.SessionStor sess, err := session.NewSession(config) if err != nil { - log.Println(err) return nil, err } - dss := &DynamoDBSessionStorage{db: dynamodb.New(sess)} + dss := &DynamoDBSessionStorage{ + logger: logger, + db: dynamodb.New(sess), + } err = dss.ensureTable() return dss, err } @@ -122,7 +129,6 @@ func (dss *DynamoDBSessionStorage) ProlongSession(id string, newDuration model.S func (dss *DynamoDBSessionStorage) ensureTable() error { exists, err := dss.isTableExists(adminSessionsTableName) if err != nil { - log.Println("Error checking admins sessions table existence:", err) return err } if exists { @@ -148,7 +154,7 @@ func (dss *DynamoDBSessionStorage) ensureTable() error { _, err = dss.db.CreateTable(input) if err != nil { - return fmt.Errorf("Cannot create admin sessions table: %s", err) + return fmt.Errorf("cannot create admin sessions table: %w", err) } ttlSpecification := &dynamodb.TimeToLiveSpecification{ @@ -165,11 +171,16 @@ func (dss *DynamoDBSessionStorage) ensureTable() error { // Then table must be in creating status. Let's give it some time. for i := 0; i < 5; i++ { time.Sleep(5 * time.Second) - log.Println("Retry setting expiration time...") + + dss.logger.Info("Retry setting expiration time...") + if _, err = dss.db.UpdateTimeToLive(ttlInput); err == nil { - log.Println("Expiration time successfully set") + dss.logger.Info("Expiration time successfully set") break } + + dss.logger.Error("Error setting expiration time", + logging.FieldError, err) } } } @@ -188,7 +199,6 @@ func (dss *DynamoDBSessionStorage) isTableExists(table string) (bool, error) { return false, nil } if err != nil { - log.Println(err) return false, err } diff --git a/storage/dynamodb/token.go b/storage/dynamodb/token.go index 9e6e303d..4ef5bbfc 100644 --- a/storage/dynamodb/token.go +++ b/storage/dynamodb/token.go @@ -1,18 +1,23 @@ package dynamodb import ( - "log" + "fmt" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) const tokensTableName = "RefreshTokens" // NewTokenStorage creates new DynamoDB token storage. -func NewTokenStorage(settings model.DynamoDatabaseSettings) (model.TokenStorage, error) { +func NewTokenStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.TokenStorage, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -23,22 +28,25 @@ func NewTokenStorage(settings model.DynamoDatabaseSettings) (model.TokenStorage, return nil, err } - ts := &TokenStorage{db: db} + ts := &TokenStorage{ + logger: logger, + db: db, + } err = ts.ensureTable() return ts, err } // TokenStorage is a DynamoDB token storage. type TokenStorage struct { - db *DB + logger *slog.Logger + db *DB } // ensureTable ensures that token storage exists in the database. func (ts *TokenStorage) ensureTable() error { exists, err := ts.db.IsTableExists(tokensTableName) if err != nil { - log.Printf("Error while checking if %s exists: %v", tokensTableName, err) - return err + return fmt.Errorf("error while checking if %s exists: %w", tokensTableName, err) } if exists { return nil @@ -62,8 +70,7 @@ func (ts *TokenStorage) ensureTable() error { } if _, err = ts.db.C.CreateTable(input); err != nil { - log.Printf("Error while creating %s table: %v", tokensTableName, err) - return err + return fmt.Errorf("error while creating %s table: %w", tokensTableName, err) } return nil } @@ -79,7 +86,7 @@ func (ts *TokenStorage) SaveToken(token string) error { t, err := dynamodbattribute.MarshalMap(Token{Token: token}) if err != nil { - log.Println(err) + ts.logger.Error("Error while marshaling token to db", logging.FieldError, err) return ErrorInternalError } @@ -89,7 +96,7 @@ func (ts *TokenStorage) SaveToken(token string) error { } if _, err = ts.db.C.PutItem(input); err != nil { - log.Println("Error while putting token to db:", err) + ts.logger.Error("Error while putting token to db", logging.FieldError, err) return ErrorInternalError } return nil @@ -110,7 +117,7 @@ func (ts *TokenStorage) HasToken(token string) bool { }, }) if err != nil { - log.Println("Error while fetching token from db:", err) + ts.logger.Error("Error while fetching token from db", logging.FieldError, err) return false } // empty result @@ -133,7 +140,7 @@ func (ts *TokenStorage) DeleteToken(token string) error { }, }, }); err != nil { - log.Println("Error while deleting token from db:", err) + ts.logger.Error("Error while deleting token from db", logging.FieldError, err) return ErrorInternalError } return nil diff --git a/storage/dynamodb/token_blocklist.go b/storage/dynamodb/token_blocklist.go index 8fe2a675..a2f662d4 100644 --- a/storage/dynamodb/token_blocklist.go +++ b/storage/dynamodb/token_blocklist.go @@ -1,18 +1,23 @@ package dynamodb import ( - "log" + "fmt" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) const blacklistedTokensTableName = "BlacklistedTokens" // NewTokenBlacklist creates new DynamoDB token storage. -func NewTokenBlacklist(settings model.DynamoDatabaseSettings) (model.TokenBlacklist, error) { +func NewTokenBlacklist( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.TokenBlacklist, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -23,23 +28,27 @@ func NewTokenBlacklist(settings model.DynamoDatabaseSettings) (model.TokenBlackl return nil, err } - ts := &TokenBlacklist{db: db} + ts := &TokenBlacklist{ + logger: logger, + db: db, + } err = ts.ensureTable() return ts, err } // TokenBlacklist is a DynamoDB storage for blacklisted tokens. type TokenBlacklist struct { - db *DB + logger *slog.Logger + db *DB } // ensureTable ensures that token blacklist exists. func (tb *TokenBlacklist) ensureTable() error { exists, err := tb.db.IsTableExists(blacklistedTokensTableName) if err != nil { - log.Printf("Error while checking if %s exists: %v", blacklistedTokensTableName, err) - return err + return fmt.Errorf("error while checking if %s exists: %w", blacklistedTokensTableName, err) } + if exists { return nil } @@ -62,8 +71,7 @@ func (tb *TokenBlacklist) ensureTable() error { } if _, err = tb.db.C.CreateTable(input); err != nil { - log.Printf("Error while creating %s table: %v", blacklistedTokensTableName, err) - return err + return fmt.Errorf("error while creating %s table: %w", blacklistedTokensTableName, err) } return nil } @@ -79,7 +87,7 @@ func (tb *TokenBlacklist) Add(token string) error { t, err := dynamodbattribute.MarshalMap(Token{Token: token}) if err != nil { - log.Println(err) + tb.logger.Error("Error while marshaling token", logging.FieldError, err) return ErrorInternalError } @@ -89,7 +97,7 @@ func (tb *TokenBlacklist) Add(token string) error { } if _, err = tb.db.C.PutItem(input); err != nil { - log.Println("Error while putting token to blacklist:", err) + tb.logger.Error("Error while putting token to blacklist", logging.FieldError, err) return ErrorInternalError } return nil @@ -110,7 +118,7 @@ func (tb *TokenBlacklist) IsBlacklisted(token string) bool { }, }) if err != nil { - log.Println("Error while fetching token from db:", err) + tb.logger.Error("Error while fetching token from db", logging.FieldError, err) return false } diff --git a/storage/dynamodb/user.go b/storage/dynamodb/user.go index 9cd3fa70..77e2ef4b 100644 --- a/storage/dynamodb/user.go +++ b/storage/dynamodb/user.go @@ -3,7 +3,7 @@ package dynamodb import ( "encoding/json" "errors" - "log" + "log/slog" "strconv" "strings" "time" @@ -11,6 +11,7 @@ import ( "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" "golang.org/x/crypto/bcrypt" @@ -43,7 +44,10 @@ type federatedUserID struct { } // NewUserStorage creates and provisions new user storage instance. -func NewUserStorage(settings model.DynamoDatabaseSettings) (model.UserStorage, error) { +func NewUserStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.UserStorage, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -54,21 +58,24 @@ func NewUserStorage(settings model.DynamoDatabaseSettings) (model.UserStorage, e return nil, err } - us := &UserStorage{db: db} + us := &UserStorage{ + logger: logger, + db: db} err = us.ensureTable() return us, err } // UserStorage stores and manages data in DynamoDB storage. type UserStorage struct { - db *DB + logger *slog.Logger + db *DB } // UserByID returns user by its ID. func (us *UserStorage) UserByID(id string) (model.User, error) { idx, err := xid.FromString(id) if err != nil { - log.Println("Incorrect user ID: ", id) + us.logger.Error("Incorrect user ID", logging.FieldError, id) return model.User{}, model.ErrorWrongDataFormat } @@ -81,7 +88,7 @@ func (us *UserStorage) UserByID(id string) (model.User, error) { }, }) if err != nil { - log.Println("Error getting item from DynamoDB:", err) + us.logger.Error("Error getting item from DynamoDB:", err) return model.User{}, ErrorInternalError } if result.Item == nil { @@ -90,7 +97,7 @@ func (us *UserStorage) UserByID(id string) (model.User, error) { userdata := model.User{} if err = dynamodbattribute.UnmarshalMap(result.Item, &userdata); err != nil { - log.Println("error while unmarshal item: ", err) + us.logger.Error("error while unmarshal item", logging.FieldError, err) return model.User{}, ErrorInternalError } return userdata, nil @@ -115,7 +122,7 @@ func (us *UserStorage) userIDByFederatedID(provider string, id string) (string, }, }) if err != nil { - log.Println("error getting item from DynamoDB: ", err) + us.logger.Error("Error getting item from DynamoDB", logging.FieldError, err) return "", ErrorInternalError } if result.Item == nil { @@ -124,7 +131,7 @@ func (us *UserStorage) userIDByFederatedID(provider string, id string) (string, fedData := federatedUserID{} if err = dynamodbattribute.UnmarshalMap(result.Item, &fedData); err != nil || len(fedData.UserID) == 0 { - log.Println("error while unmarshal item: ", err) + us.logger.Error("Error while unmarshal item", logging.FieldError, err) return "", ErrorInternalError } @@ -189,7 +196,7 @@ func (us *UserStorage) userIdxByName(name string) (*userIndexByNameData, error) Select: aws.String("ALL_PROJECTED_ATTRIBUTES"), // retrieve all attributes, because we need to make local check. }) if err != nil { - log.Println("Error querying for items:", err) + us.logger.Error("Error querying for items", logging.FieldError, err) return nil, ErrorInternalError } if len(result.Items) == 0 { @@ -199,7 +206,7 @@ func (us *UserStorage) userIdxByName(name string) (*userIndexByNameData, error) item := result.Items[0] userdata := new(userIndexByNameData) if err = dynamodbattribute.UnmarshalMap(item, userdata); err != nil { - log.Println("error while unmarshal item:", err) + us.logger.Error("Error while unmarshal item", logging.FieldError, err) return nil, ErrorInternalError } return userdata, nil @@ -217,7 +224,7 @@ func (us *UserStorage) userIdxByPhone(phone string) (*userIndexByPhoneData, erro Select: aws.String("ALL_PROJECTED_ATTRIBUTES"), }) if err != nil { - log.Println("error querying for user by phone number: ", err) + us.logger.Error("Error querying for user by phone number", logging.FieldError, err) return nil, ErrorInternalError } if len(result.Items) == 0 { @@ -227,7 +234,7 @@ func (us *UserStorage) userIdxByPhone(phone string) (*userIndexByPhoneData, erro item := result.Items[0] userdata := new(userIndexByPhoneData) if err = dynamodbattribute.UnmarshalMap(item, userdata); err != nil { - log.Println("error while unmarshal user: ", err) + us.logger.Error("Error while unmarshal user", logging.FieldError, err) return nil, ErrorInternalError } return userdata, nil @@ -238,13 +245,13 @@ func (us *UserStorage) UserByUsername(username string) (model.User, error) { username = strings.ToLower(username) userIdx, err := us.userIdxByName(username) if err != nil { - log.Println("error getting user by name: ", err) + us.logger.Error("Error getting user by name", logging.FieldError, err) return model.User{}, err } user, err := us.UserByID(userIdx.ID) if err != nil { - log.Println("error querying user by id: ", err) + us.logger.Error("Error querying user by id", logging.FieldError, err) return model.User{}, ErrorInternalError } // clear password hash @@ -256,13 +263,13 @@ func (us *UserStorage) UserByUsername(username string) (model.User, error) { func (us *UserStorage) UserByPhone(phone string) (model.User, error) { userIdx, err := us.userIdxByPhone(phone) if err != nil { - log.Println("error getting user by phone: ", err) + us.logger.Error("Error getting user by phone", logging.FieldError, err) return model.User{}, err } user, err := us.UserByID(userIdx.ID) if err != nil { - log.Println("error querying user by id: ", err) + us.logger.Error("Error querying user by id", logging.FieldError, err) return model.User{}, ErrorInternalError } // clear password hash @@ -299,7 +306,7 @@ func (us *UserStorage) addNewUser(u model.User) (model.User, error) { u.NumOfLogins = 0 uv, err := dynamodbattribute.MarshalMap(u) if err != nil { - log.Println("error marshalling user: ", err) + us.logger.Error("Error marshalling user", logging.FieldError, err) return model.User{}, ErrorInternalError } @@ -308,7 +315,7 @@ func (us *UserStorage) addNewUser(u model.User) (model.User, error) { TableName: aws.String(usersTableName), } if _, err = us.db.C.PutItem(input); err != nil { - log.Println("error putting item: ", err) + us.logger.Error("Error putting item", logging.FieldError, err) return model.User{}, ErrorInternalError } return u, err @@ -358,7 +365,7 @@ func (us *UserStorage) AddUserWithPassword(user model.User, password, role strin func (us *UserStorage) AddUserWithFederatedID(user model.User, provider string, federatedID, role string) (model.User, error) { _, err := us.userIDByFederatedID(provider, federatedID) if err != nil && err != model.ErrUserNotFound { - log.Println("error getting user by name: ", err) + us.logger.Error("error getting user by name", logging.FieldError, err) return model.User{}, err } else if err == nil { return model.User{}, model.ErrorUserExists @@ -371,14 +378,14 @@ func (us *UserStorage) AddUserWithFederatedID(user model.User, provider string, user, creationErr := us.AddNewUser(user, "") if creationErr != nil { - log.Println("error adding new user: ", creationErr) + us.logger.Error("Error adding new user", logging.FieldError, creationErr) return model.User{}, creationErr } fedData := federatedUserID{FederatedID: fid, UserID: user.ID} fedInputData, err := dynamodbattribute.MarshalMap(fedData) if err != nil { - log.Println("error marshalling federated data: ", err) + us.logger.Error("error marshalling federated data", logging.FieldError, err) return model.User{}, ErrorInternalError } @@ -387,7 +394,7 @@ func (us *UserStorage) AddUserWithFederatedID(user model.User, provider string, TableName: aws.String(usersFederatedIDTableName), } if _, err = us.db.C.PutItem(input); err != nil { - log.Println("error putting item: ", err) + us.logger.Error("error putting item", logging.FieldError, err) return model.User{}, ErrorInternalError } @@ -397,7 +404,7 @@ func (us *UserStorage) AddUserWithFederatedID(user model.User, provider string, // UpdateUser updates user in DynamoDB storage. func (us *UserStorage) UpdateUser(userID string, user model.User) (model.User, error) { if _, err := xid.FromString(userID); err != nil { - log.Println("incorrect userID: ", userID) + us.logger.Error("incorrect userID", logging.FieldUserID, userID) return model.User{}, model.ErrorWrongDataFormat } @@ -407,7 +414,7 @@ func (us *UserStorage) UpdateUser(userID string, user model.User) (model.User, e } if err := us.DeleteUser(userID); err != nil { - log.Println("error deleting old user: ", err) + us.logger.Error("error deleting old user", logging.FieldError, err) return model.User{}, err } @@ -424,7 +431,9 @@ func (us *UserStorage) UpdateUser(userID string, user model.User) (model.User, e func (us *UserStorage) ResetPassword(id, password string) error { idx, err := xid.FromString(id) if err != nil { - log.Println("Incorrect user ID: ", id) + us.logger.Error("Incorrect user ID", + logging.FieldError, id, + logging.FieldError, err) return model.ErrorWrongDataFormat } @@ -462,7 +471,9 @@ func (us *UserStorage) CheckPassword(id, password string) error { func (us *UserStorage) ResetUsername(id, username string) error { idx, err := xid.FromString(id) if err != nil { - log.Println("Incorrect user ID: ", id) + us.logger.Error("Incorrect user ID", + logging.FieldUserID, id, + logging.FieldError, err) return model.ErrorWrongDataFormat } @@ -498,7 +509,7 @@ func (us *UserStorage) FetchUsers(filterString string, skip, limit int) ([]model result, err := us.db.C.Scan(scanInput) if err != nil { - log.Println("error querying for users: ", err) + us.logger.Error("Error querying for users", logging.FieldError, err) return []model.User{}, 0, ErrorInternalError } @@ -509,7 +520,7 @@ func (us *UserStorage) FetchUsers(filterString string, skip, limit int) ([]model } user := model.User{} if err = dynamodbattribute.UnmarshalMap(result.Items[i], &user); err != nil { - log.Println("error while unmarshal user: ", err) + us.logger.Error("Error while unmarshal user", logging.FieldError, err) return []model.User{}, 0, ErrorInternalError } users[i] = user @@ -542,12 +553,16 @@ func (us *UserStorage) ImportJSON(data []byte, clearOldData bool) error { // UpdateLoginMetadata updates user's login metadata. func (us *UserStorage) UpdateLoginMetadata(userID string) { if _, err := xid.FromString(userID); err != nil { - log.Println("Incorrect userID: ", userID) + us.logger.Error("Incorrect userID", + logging.FieldUserID, userID, + logging.FieldError, err) return } if _, err := us.UserByID(userID); err != nil { - log.Println("Cannot get user by ID: ", userID) + us.logger.Error("Cannot get user by ID", + logging.FieldUserID, userID, + logging.FieldError, err) return } @@ -564,7 +579,9 @@ func (us *UserStorage) UpdateLoginMetadata(userID string) { ReturnValues: aws.String("NONE"), }) if err != nil { - log.Printf("Cannot update login metadata of user %s: %s\n", userID, err) + us.logger.Error("Cannot update login metadata of user", + logging.FieldUserID, userID, + logging.FieldError, err) return } } @@ -574,7 +591,7 @@ func (us *UserStorage) UpdateLoginMetadata(userID string) { func (us *UserStorage) ensureTable() error { exists, err := us.db.IsTableExists(usersTableName) if err != nil { - log.Println("Error checking for table existence:", err) + us.logger.Error("Error checking for table existence", logging.FieldError, err) return err } if !exists { @@ -636,7 +653,7 @@ func (us *UserStorage) ensureTable() error { TableName: aws.String(usersTableName), } if _, err = us.db.C.CreateTable(input); err != nil { - log.Println("Error creating table:", err) + us.logger.Error("Error creating table", logging.FieldError, err) return err } } @@ -644,7 +661,7 @@ func (us *UserStorage) ensureTable() error { // create table to handle federated ID's exists, err = us.db.IsTableExists(usersFederatedIDTableName) if err != nil { - log.Println("Error checking for table existence:", err) + us.logger.Error("Error checking for table existence", logging.FieldError, err) return err } if !exists { @@ -666,7 +683,7 @@ func (us *UserStorage) ensureTable() error { TableName: aws.String(usersFederatedIDTableName), } if _, err = us.db.C.CreateTable(input); err != nil { - log.Println("Error creating table:", err) + us.logger.Error("Error creating table", logging.FieldError, err) return err } } diff --git a/storage/dynamodb/verification_code.go b/storage/dynamodb/verification_code.go index d2426902..64769dcf 100644 --- a/storage/dynamodb/verification_code.go +++ b/storage/dynamodb/verification_code.go @@ -1,12 +1,13 @@ package dynamodb import ( - "log" + "log/slog" "time" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/dynamodb" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -23,7 +24,10 @@ const ( ) // NewVerificationCodeStorage creates and provisions new DynamoDB verification code storage. -func NewVerificationCodeStorage(settings model.DynamoDatabaseSettings) (model.VerificationCodeStorage, error) { +func NewVerificationCodeStorage( + logger *slog.Logger, + settings model.DynamoDatabaseSettings, +) (model.VerificationCodeStorage, error) { if len(settings.Endpoint) == 0 || len(settings.Region) == 0 { return nil, ErrorEmptyEndpointRegion } @@ -34,14 +38,18 @@ func NewVerificationCodeStorage(settings model.DynamoDatabaseSettings) (model.Ve return nil, err } - vcs := &VerificationCodeStorage{db: db} + vcs := &VerificationCodeStorage{ + logger: logger, + db: db, + } err = vcs.ensureTable() return vcs, err } // VerificationCodeStorage implements verification code storage interface. type VerificationCodeStorage struct { - db *DB + logger *slog.Logger + db *DB } // IsVerificationCodeFound checks whether verification code can be found. @@ -54,7 +62,7 @@ func (vcs *VerificationCodeStorage) IsVerificationCodeFound(phone, code string) }, }) if err != nil { - log.Println("Error querying for verification code:", err) + vcs.logger.Error("Error querying for verification code", logging.FieldError, err) return false, ErrorInternalError } if len(result.Items) == 0 { @@ -74,7 +82,7 @@ func (vcs *VerificationCodeStorage) CreateVerificationCode(phone, code string) e } if _, err := vcs.db.C.DeleteItem(delInput); err != nil { - log.Println("Error deleting old verification code: ", err) + vcs.logger.Error("Error deleting old verification code", logging.FieldError, err) return ErrorInternalError } @@ -85,7 +93,7 @@ func (vcs *VerificationCodeStorage) CreateVerificationCode(phone, code string) e expiresAtField: time.Now().Add(verificationCodesExpirationTime), }) if err != nil { - log.Println("Error marshalling verification code:", err) + vcs.logger.Error("Error marshalling verification code", logging.FieldError, err) return ErrorInternalError } @@ -95,7 +103,7 @@ func (vcs *VerificationCodeStorage) CreateVerificationCode(phone, code string) e } if _, err := vcs.db.C.PutItem(putInput); err != nil { - log.Println("Error putting verification code to database:", err) + vcs.logger.Error("Error putting verification code to database", logging.FieldError, err) return ErrorInternalError } return err @@ -105,7 +113,7 @@ func (vcs *VerificationCodeStorage) CreateVerificationCode(phone, code string) e func (vcs *VerificationCodeStorage) ensureTable() error { exists, err := vcs.db.IsTableExists(verificationCodesTableName) if err != nil { - log.Println("Error checking for verification codes table existence:", err) + vcs.logger.Error("Error checking for verification codes table existence", logging.FieldError, err) return err } if exists { @@ -130,7 +138,7 @@ func (vcs *VerificationCodeStorage) ensureTable() error { } if _, err = vcs.db.C.CreateTable(createTableInput); err != nil { - log.Println("Error creating table:", err) + vcs.logger.Error("Error creating table", logging.FieldError, err) return err } @@ -148,11 +156,15 @@ func (vcs *VerificationCodeStorage) ensureTable() error { // Then Verification Codes table must be in creating status. Let's give it some time. for i := 0; i < 5; i++ { time.Sleep(5 * time.Second) - log.Println("Retry setting expiration time...") + + vcs.logger.Info("Retry setting expiration time...") + if _, err = vcs.db.C.UpdateTimeToLive(ttlInput); err == nil { - log.Println("Expiration time successfully set") + vcs.logger.Info("Expiration time successfully set") break } + + vcs.logger.Error("Error sending expiration time", logging.FieldError, err) } } } diff --git a/storage/fs/config_storage.go b/storage/fs/config_storage.go index 85b5a78b..3dba37d1 100644 --- a/storage/fs/config_storage.go +++ b/storage/fs/config_storage.go @@ -2,16 +2,18 @@ package fs import ( "fmt" - "log" + "log/slog" "os" "path/filepath" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "gopkg.in/yaml.v2" ) // ConfigurationStorage is a wrapper over server configuration file. type ConfigurationStorage struct { + logger *slog.Logger ServerConfigPath string UpdateChan chan interface{} updateChanClosed bool @@ -20,7 +22,7 @@ type ConfigurationStorage struct { errors []error } -func NewDefaultConfigurationStorage() model.ConfigurationStorage { +func NewDefaultConfigurationStorage(logger *slog.Logger) model.ConfigurationStorage { configPaths := []string{ "./server-config.yaml", "../../server/server-config.yaml", @@ -32,13 +34,16 @@ func NewDefaultConfigurationStorage() model.ConfigurationStorage { } if fileExists(p) { cs, _ := model.ConfigStorageSettingsFromStringFile(p) - c, e := NewConfigurationStorage(cs) + c, e := NewConfigurationStorage(logger, cs) // if error, trying to other file from the list if e != nil { - log.Printf("Unable to load default config from file %s, trying other one from the list (if any)", p) + logger.Error("Unable to load default config from file, trying other one from the list (if any)", + "file", p, + logging.FieldError, e) continue } else { - log.Printf("Successfully loaded default config from file %s", p) + logger.Info("Successfully loaded default config from file", + "file", p) return c } } @@ -48,14 +53,18 @@ func NewDefaultConfigurationStorage() model.ConfigurationStorage { } // NewConfigurationStorage creates and returns new file configuration storage. -func NewConfigurationStorage(config model.FileStorageSettings) (*ConfigurationStorage, error) { - log.Println("Loading server configuration from specified file...") +func NewConfigurationStorage( + logger *slog.Logger, + config model.FileStorageSettings, +) (*ConfigurationStorage, error) { + logger.Info("Loading server configuration from specified file...") if config.Type != model.FileStorageTypeLocal { return nil, fmt.Errorf("could not create file config storage from non-file settings") } cs := &ConfigurationStorage{ + logger: logger, config: config, ServerConfigPath: config.Local.Path, UpdateChan: make(chan interface{}, 1), @@ -68,17 +77,17 @@ func NewConfigurationStorage(config model.FileStorageSettings) (*ConfigurationSt func (cs *ConfigurationStorage) WriteConfig(settings model.ServerSettings) error { ss, err := yaml.Marshal(settings) if err != nil { - return fmt.Errorf("Cannot marshall configuration: %s", err) + return fmt.Errorf("cannot marshall configuration: %s", err) } if err = os.WriteFile(cs.ServerConfigPath, ss, 0o644); err != nil { - return fmt.Errorf("Cannot write configuration file: %s", err) + return fmt.Errorf("cannot write configuration file: %s", err) } // Indicate config update. To prevent writing to a closed channel, make a check. go func() { if cs.updateChanClosed { - log.Println("Attempted to write to closed UpdateChan") + cs.logger.Info("Attempted to write to closed UpdateChan") return } cs.UpdateChan <- struct{}{} @@ -92,19 +101,19 @@ func (cs *ConfigurationStorage) LoadServerSettings(validate bool) (model.ServerS dir, err := os.Getwd() if err != nil { - cs.errors = append(cs.errors, fmt.Errorf("Cannot get server configuration file: %s", err)) + cs.errors = append(cs.errors, fmt.Errorf("cannot get server configuration file: %s", err)) return model.ServerSettings{}, cs.errors } yamlFile, err := os.ReadFile(filepath.Join(dir, cs.ServerConfigPath)) if err != nil { - cs.errors = append(cs.errors, fmt.Errorf("Cannot read server configuration file: %s", err)) + cs.errors = append(cs.errors, fmt.Errorf("cannot read server configuration file: %s", err)) return model.ServerSettings{}, cs.errors } var settings model.ServerSettings if err = yaml.Unmarshal(yamlFile, &settings); err != nil { - cs.errors = append(cs.errors, fmt.Errorf("Cannot unmarshal server configuration file: %s", err)) + cs.errors = append(cs.errors, fmt.Errorf("cannot unmarshal server configuration file: %s", err)) return model.ServerSettings{}, cs.errors } diff --git a/storage/fs_watcher.go b/storage/fs_watcher.go index 5ebe56e5..d6cb0808 100644 --- a/storage/fs_watcher.go +++ b/storage/fs_watcher.go @@ -2,15 +2,17 @@ package storage import ( "io/fs" - "log" + "log/slog" "strings" "time" + "github.com/madappgang/identifo/v2/logging" "golang.org/x/exp/slices" ) // FSWatcher watch for files changes in FS and notifies on file change type FSWatcher struct { + logger *slog.Logger f fs.FS keys []string poll time.Duration @@ -33,9 +35,15 @@ func KeysWithFixedSlashed(keys []string) []string { return result } -func NewFSWatcher(f fs.FS, keys []string, poll time.Duration) *FSWatcher { +func NewFSWatcher( + logger *slog.Logger, + f fs.FS, + keys []string, + poll time.Duration, +) *FSWatcher { // let's remove trailing return &FSWatcher{ + logger: logger, f: f, keys: KeysWithFixedSlashed(keys), poll: poll, @@ -70,11 +78,11 @@ func (w *FSWatcher) runWatch() { for { select { case <-time.After(w.poll): - log.Println("fs watcher checking the files ...") + w.logger.Info("fs watcher checking the files ...") go w.checkUpdatedFiles() case <-w.done: w.isWatching = false - log.Println("fs watcher has received done signal and stopping itself ...") + w.logger.Info("fs watcher has received done signal and stopping itself ...") return } } @@ -85,7 +93,7 @@ func (w *FSWatcher) checkUpdatedFiles() { for _, key := range w.keys { stat, err := fs.Stat(w.f, key) if err != nil { - log.Printf("getting error: %+v\n", err) + w.logger.Error("fs watcher getting error", logging.FieldError, err) w.err <- err continue } @@ -95,7 +103,7 @@ func (w *FSWatcher) checkUpdatedFiles() { } } if len(modifiedKeys) > 0 { - log.Printf("fs files has changed response: %+v", modifiedKeys) + w.logger.Info("fs files has changed response", "keys", modifiedKeys) // report file change w.change <- modifiedKeys } diff --git a/storage/fs_watcher_test.go b/storage/fs_watcher_test.go index fd5b2d95..59c0ef31 100644 --- a/storage/fs_watcher_test.go +++ b/storage/fs_watcher_test.go @@ -10,6 +10,7 @@ import ( "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/s3" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage" s3s "github.com/madappgang/identifo/v2/storage/s3" @@ -37,7 +38,11 @@ func TestNewFSWatcher(t *testing.T) { time.Sleep(time.Second * 1) - watcher := storage.NewFSWatcher(fss, []string{"test1.txt", "test2.txt"}, time.Second*2) + watcher := storage.NewFSWatcher( + logging.DefaultLogger, + fss, + []string{"test1.txt", "test2.txt"}, + time.Second*2) watcher.Watch() go func() { @@ -101,7 +106,11 @@ func TestNewFSWatcherS3(t *testing.T) { time.Sleep(time.Second * 1) - watcher := storage.NewFSWatcher(fss, []string{"watched.txt", "watched_new.txt"}, time.Second*2) + watcher := storage.NewFSWatcher( + logging.DefaultLogger, + fss, + []string{"watched.txt", "watched_new.txt"}, + time.Second*2) watcher.Watch() go func() { @@ -170,7 +179,7 @@ func getS3Client(t *testing.T, endpoint string) *s3.S3 { return s3client } -func uploadS3File(t *testing.T, s3client *s3.S3, s model.FileStorageS3, key string) { +func uploadS3File(t *testing.T, s3client *s3.S3, _ model.FileStorageS3, key string) { newFilecontent := []byte(fmt.Sprintf("This content has been changed at %v", time.Now().Unix())) input := &s3.PutObjectInput{ Bucket: aws.String("identifo"), diff --git a/storage/invite.go b/storage/invite.go index cd825a9f..d58b2fd4 100644 --- a/storage/invite.go +++ b/storage/invite.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -11,14 +12,16 @@ import ( ) // NewInviteStorage creates new invite storage from settings -func NewInviteStorage(settings model.DatabaseSettings) (model.InviteStorage, error) { +func NewInviteStorage( + logger *slog.Logger, + settings model.DatabaseSettings) (model.InviteStorage, error) { switch settings.Type { case model.DBTypeBoltDB: - return boltdb.NewInviteStorage(settings.BoltDB) + return boltdb.NewInviteStorage(logger, settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewInviteStorage(settings.Mongo) + return mongo.NewInviteStorage(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewInviteStorage(settings.Dynamo) + return dynamodb.NewInviteStorage(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: diff --git a/storage/keys.go b/storage/keys.go index 31298362..a3d8430d 100644 --- a/storage/keys.go +++ b/storage/keys.go @@ -2,18 +2,22 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/fs" "github.com/madappgang/identifo/v2/storage/s3" ) -func NewKeyStorage(settings model.FileStorageSettings) (model.KeyStorage, error) { +func NewKeyStorage( + logger *slog.Logger, + settings model.FileStorageSettings, +) (model.KeyStorage, error) { switch settings.Type { case model.FileStorageTypeLocal: return fs.NewKeyStorage(settings.Local) case model.FileStorageTypeS3: - return s3.NewKeyStorage(settings.S3) + return s3.NewKeyStorage(logger, settings.S3) default: return nil, fmt.Errorf("unknown key storage type: %s", settings.Type) } diff --git a/storage/management_keys.go b/storage/management_keys.go index 9fc5a76a..989c55b9 100644 --- a/storage/management_keys.go +++ b/storage/management_keys.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -11,14 +12,17 @@ import ( ) // NewManagementKeys creates new management keys storage from settings. -func NewManagementKeys(settings model.DatabaseSettings) (model.ManagementKeysStorage, error) { +func NewManagementKeys( + logger *slog.Logger, + settings model.DatabaseSettings, +) (model.ManagementKeysStorage, error) { switch settings.Type { case model.DBTypeBoltDB: return boltdb.NewManagementKeysStorage(settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewManagementKeysStorage(settings.Mongo) + return mongo.NewManagementKeysStorage(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewManagementKeysStorage(settings.Dynamo) + return dynamodb.NewManagementKeysStorage(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: diff --git a/storage/mem/app.go b/storage/mem/app.go index 75cb257e..0960f05b 100644 --- a/storage/mem/app.go +++ b/storage/mem/app.go @@ -2,20 +2,25 @@ package mem import ( "encoding/json" - "log" + "log/slog" "strings" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/rs/xid" ) // NewAppStorage creates new in-memory AppStorage implementation. -func NewAppStorage() (model.AppStorage, error) { - return &AppStorage{storage: make(map[string]model.AppData)}, nil +func NewAppStorage(logger *slog.Logger) (model.AppStorage, error) { + return &AppStorage{ + logger: logger, + storage: make(map[string]model.AppData), + }, nil } // AppStorage is a fully functional app storage. type AppStorage struct { + logger *slog.Logger storage map[string]model.AppData } @@ -102,7 +107,7 @@ func (as *AppStorage) ImportJSON(data []byte, cleanOldData bool) error { apd := []model.AppData{} if err := json.Unmarshal(data, &apd); err != nil { - log.Println("error while unmarshal app data: ", err) + as.logger.Error("error while unmarshal app data", logging.FieldError, err) return err } for _, a := range apd { diff --git a/storage/mongo/app.go b/storage/mongo/app.go index 58241e91..04aa3ae7 100644 --- a/storage/mongo/app.go +++ b/storage/mongo/app.go @@ -3,9 +3,10 @@ package mongo import ( "context" "encoding/json" - "log" + "log/slog" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson/primitive" @@ -16,23 +17,31 @@ import ( const appsCollectionName = "Applications" // NewAppStorage creates new MongoDB AppStorage implementation. -func NewAppStorage(settings model.MongoDatabaseSettings) (model.AppStorage, error) { +func NewAppStorage( + logger *slog.Logger, + settings model.MongoDatabaseSettings, +) (model.AppStorage, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(appsCollectionName) - return &AppStorage{coll: coll, timeout: 30 * time.Second}, nil + coll := db.database.Collection(appsCollectionName) + return &AppStorage{ + logger: logger, + coll: coll, + timeout: 30 * time.Second, + }, nil } // AppStorage is a fully functional app storage for MongoDB. type AppStorage struct { + logger *slog.Logger coll *mongo.Collection timeout time.Duration } @@ -173,7 +182,7 @@ func (as *AppStorage) ClearAllData() { defer cancel() if _, err := as.coll.DeleteMany(ctx, bson.M{}); err != nil { - log.Printf("Error cleaning all user data: %s\n", err) + as.logger.Error("Error cleaning all user data", logging.FieldError, err) } } @@ -185,7 +194,6 @@ func (as *AppStorage) ImportJSON(data []byte, cleanOldData bool) error { apd := []model.AppData{} if err := json.Unmarshal(data, &apd); err != nil { - log.Println(err) return err } for _, a := range apd { diff --git a/storage/mongo/database_connection_tester.go b/storage/mongo/database_connection_tester.go index e5e046f2..0397893e 100644 --- a/storage/mongo/database_connection_tester.go +++ b/storage/mongo/database_connection_tester.go @@ -1,6 +1,7 @@ package mongo import ( + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -8,8 +9,7 @@ type ConnectionTester struct { settings model.MongoDatabaseSettings } -// NewConnectionTester creates a BoltDB connection tester - +// NewConnectionTester creates a MongoFB connection tester func NewConnectionTester(settings model.MongoDatabaseSettings) model.ConnectionTester { return &ConnectionTester{settings: settings} } @@ -20,10 +20,16 @@ func (ct *ConnectionTester) Connect() error { } // create or connect to database - _, err := NewDB(ct.settings.ConnectionString, ct.settings.DatabaseName) + db, err := NewDB( + logging.DefaultLogger, + ct.settings.ConnectionString, + ct.settings.DatabaseName, + ) if err != nil { return err } + db.Close() + return nil } diff --git a/storage/mongo/invite.go b/storage/mongo/invite.go index 8b2024f5..0ce898b9 100644 --- a/storage/mongo/invite.go +++ b/storage/mongo/invite.go @@ -3,6 +3,7 @@ package mongo import ( "context" "errors" + "log/slog" "time" "github.com/madappgang/identifo/v2/model" @@ -21,18 +22,21 @@ type InviteStorage struct { } // NewInviteStorage creates a MongoDB invite storage. -func NewInviteStorage(settings model.MongoDatabaseSettings) (model.InviteStorage, error) { +func NewInviteStorage( + logger *slog.Logger, + settings model.MongoDatabaseSettings, +) (model.InviteStorage, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(invitesCollectionName) + coll := db.database.Collection(invitesCollectionName) return &InviteStorage{coll: coll, timeout: 30 * time.Second}, nil } diff --git a/storage/mongo/management_keys.go b/storage/mongo/management_keys.go index b8bcb852..6df8d9c7 100644 --- a/storage/mongo/management_keys.go +++ b/storage/mongo/management_keys.go @@ -4,9 +4,11 @@ import ( "context" "encoding/json" "errors" - "log" + "fmt" + "log/slog" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson/primitive" @@ -18,23 +20,30 @@ const managementKeysCollectionName = "ManagementKeys" // ManagementKeysStorage is a MongoDB management keys storage. type ManagementKeysStorage struct { - coll *mongo.Collection + logger *slog.Logger + coll *mongo.Collection } // NewManagementKeysStorage creates a management keys invite storage. -func NewManagementKeysStorage(settings model.MongoDatabaseSettings) (model.ManagementKeysStorage, error) { +func NewManagementKeysStorage( + logger *slog.Logger, + settings model.MongoDatabaseSettings, +) (model.ManagementKeysStorage, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(managementKeysCollectionName) - return &ManagementKeysStorage{coll: coll}, nil + coll := db.database.Collection(managementKeysCollectionName) + return &ManagementKeysStorage{ + logger: logger, + coll: coll, + }, nil } func (ms *ManagementKeysStorage) GetKey(ctx context.Context, id string) (model.ManagementKey, error) { @@ -136,7 +145,8 @@ func (ms *ManagementKeysStorage) ClearAllData() { defer cancel() if _, err := ms.coll.DeleteMany(ctx, bson.M{}); err != nil { - log.Printf("Error cleaning all user data: %s\n", err) + ms.logger.Error("Error cleaning all user data", + logging.FieldError, err) } } @@ -148,12 +158,12 @@ func (ms *ManagementKeysStorage) ImportJSON(data []byte, cleanOldData bool) erro keys := []model.ManagementKey{} if err := json.Unmarshal(data, &keys); err != nil { - log.Println(err) - return err + return fmt.Errorf("failed to unmarshal management keys: %w", err) } + for _, a := range keys { if _, err := ms.AddKey(context.TODO(), a); err != nil { - return err + return fmt.Errorf("failed to add management keys: %w", err) } } return nil diff --git a/storage/mongo/mongo.go b/storage/mongo/mongo.go index cd02eaa2..1126ddae 100644 --- a/storage/mongo/mongo.go +++ b/storage/mongo/mongo.go @@ -3,19 +3,19 @@ package mongo import ( "bytes" "context" - "errors" "fmt" - "log" + "log/slog" "strings" "time" + "github.com/madappgang/identifo/v2/logging" "go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/mongo" "go.mongodb.org/mongo-driver/mongo/options" ) // NewDB creates new database connection. -func NewDB(conn string, dbName string) (*DB, error) { +func NewDB(logger *slog.Logger, conn string, dbName string) (*DB, error) { ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) defer cancel() @@ -28,28 +28,30 @@ func NewDB(conn string, dbName string) (*DB, error) { return nil, err } db := &DB{ - Client: client, - Database: client.Database(dbName), + logger: logger, + client: client, + database: client.Database(dbName), } return db, nil } // DB is database connection structure. type DB struct { - Database *mongo.Database - Client *mongo.Client + logger *slog.Logger + database *mongo.Database + client *mongo.Client } // Close closes database connection. func (db *DB) Close() { - if err := db.Client.Disconnect(context.TODO()); err != nil { - log.Printf("Error closing mongo storage: %s\n", err) + if err := db.client.Disconnect(context.TODO()); err != nil { + db.logger.Error("Error closing mongo storage", logging.FieldError, err) } } // EnsureCollectionIndices creates indices on a collection. func (db *DB) EnsureCollectionIndices(collectionName string, newIndices []mongo.IndexModel) error { - coll := db.Database.Collection(collectionName) + coll := db.database.Collection(collectionName) ctx, cancel := context.WithTimeout(context.Background(), 2*time.Minute) defer cancel() @@ -81,7 +83,7 @@ func generateIndexName(index mongo.IndexModel) (string, error) { keys, ok := index.Keys.(bson.D) if !ok { - return "", errors.New("incorrect index keys type - expecting bsonx.Doc") + return "", fmt.Errorf("incorrect index keys type - expecting bson.D") } for _, elem := range keys { if !first { diff --git a/storage/mongo/token_blacklist.go b/storage/mongo/token_blacklist.go index 1a8e82cf..c5d444a4 100644 --- a/storage/mongo/token_blacklist.go +++ b/storage/mongo/token_blacklist.go @@ -3,6 +3,7 @@ package mongo import ( "context" "fmt" + "log/slog" "time" "github.com/madappgang/identifo/v2/model" @@ -14,18 +15,21 @@ import ( const blacklistedTokensCollectionName = "BlacklistedTokens" // NewTokenBlacklist creates new MongoDB-backed token blacklist. -func NewTokenBlacklist(settings model.MongoDatabaseSettings) (model.TokenBlacklist, error) { +func NewTokenBlacklist( + logger *slog.Logger, + settings model.MongoDatabaseSettings, +) (model.TokenBlacklist, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(blacklistedTokensCollectionName) + coll := db.database.Collection(blacklistedTokensCollectionName) // TODO: check that index exists for other DB's err = db.EnsureCollectionIndices(blacklistedTokensCollectionName, []mongo.IndexModel{ diff --git a/storage/mongo/token_refresh.go b/storage/mongo/token_refresh.go index dfa5d74b..49dee759 100644 --- a/storage/mongo/token_refresh.go +++ b/storage/mongo/token_refresh.go @@ -3,6 +3,7 @@ package mongo import ( "context" "fmt" + "log/slog" "time" "github.com/madappgang/identifo/v2/model" @@ -14,18 +15,21 @@ import ( const tokensCollectionName = "RefreshTokens" // NewTokenStorage creates a MongoDB token storage. -func NewTokenStorage(settings model.MongoDatabaseSettings) (model.TokenStorage, error) { +func NewTokenStorage( + logger *slog.Logger, + settings model.MongoDatabaseSettings, +) (model.TokenStorage, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(tokensCollectionName) + coll := db.database.Collection(tokensCollectionName) // TODO: check that index exists for other DB's err = db.EnsureCollectionIndices(tokensCollectionName, []mongo.IndexModel{ diff --git a/storage/mongo/user.go b/storage/mongo/user.go index ff4619b4..859d5110 100644 --- a/storage/mongo/user.go +++ b/storage/mongo/user.go @@ -4,10 +4,11 @@ import ( "context" "encoding/json" "errors" - "log" + "log/slog" "strings" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "go.mongodb.org/mongo-driver/bson" "go.mongodb.org/mongo-driver/bson/primitive" @@ -19,19 +20,25 @@ import ( const usersCollectionName = "Users" // NewUserStorage creates and inits MongoDB user storage. -func NewUserStorage(settings model.MongoDatabaseSettings) (model.UserStorage, error) { +func NewUserStorage( + logger *slog.Logger, + settings model.MongoDatabaseSettings) (model.UserStorage, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(usersCollectionName) - us := &UserStorage{coll: coll, timeout: 30 * time.Second} + coll := db.database.Collection(usersCollectionName) + us := &UserStorage{ + logger: logger, + coll: coll, + timeout: 30 * time.Second, + } userNameIndexOptions := &options.IndexOptions{} userNameIndexOptions.SetUnique(false) @@ -67,6 +74,7 @@ func NewUserStorage(settings model.MongoDatabaseSettings) (model.UserStorage, er // UserStorage implements user storage interface. type UserStorage struct { + logger *slog.Logger coll *mongo.Collection timeout time.Duration } @@ -270,7 +278,7 @@ func (us *UserStorage) AddUserWithFederatedID(user model.User, provider string, return model.User{}, model.ErrorUserExists } - // unknown error during user existnce check + // unknown error during user existence check if !errors.Is(err, model.ErrUserNotFound) { return model.User{}, err } @@ -455,7 +463,9 @@ func (us *UserStorage) ImportJSON(data []byte, clearOldData bool) error { func (us *UserStorage) UpdateLoginMetadata(userID string) { hexID, err := primitive.ObjectIDFromHex(userID) if err != nil { - log.Printf("Cannot update login metadata of user %s: %s\n", userID, err) + us.logger.Error("Cannot update login metadata of user", + logging.FieldUserID, userID, + logging.FieldError, err) return } @@ -469,7 +479,9 @@ func (us *UserStorage) UpdateLoginMetadata(userID string) { var ud model.User if err := us.coll.FindOneAndUpdate(ctx, bson.M{"_id": hexID.Hex()}, update).Decode(&ud); err != nil { - log.Printf("Cannot update login metadata of user %s: %s\n", userID, err) + us.logger.Error("Cannot update login metadata of user", + logging.FieldUserID, userID, + logging.FieldError, err) } } @@ -482,6 +494,7 @@ func (us *UserStorage) ClearAllUserData() { defer cancel() if _, err := us.coll.DeleteMany(ctx, bson.M{}); err != nil { - log.Printf("Error cleaning all user data: %s\n", err) + us.logger.Error("Error cleaning all user data", + logging.FieldError, err) } } diff --git a/storage/mongo/verification_code.go b/storage/mongo/verification_code.go index 4e292a76..0b286456 100644 --- a/storage/mongo/verification_code.go +++ b/storage/mongo/verification_code.go @@ -2,6 +2,7 @@ package mongo import ( "context" + "log/slog" "time" "github.com/madappgang/identifo/v2/model" @@ -17,18 +18,21 @@ const ( ) // NewVerificationCodeStorage creates and inits MongoDB verification code storage. -func NewVerificationCodeStorage(settings model.MongoDatabaseSettings) (model.VerificationCodeStorage, error) { +func NewVerificationCodeStorage( + logger *slog.Logger, + settings model.MongoDatabaseSettings, +) (model.VerificationCodeStorage, error) { if len(settings.ConnectionString) == 0 || len(settings.DatabaseName) == 0 { return nil, ErrorEmptyConnectionStringDatabase } // create database - db, err := NewDB(settings.ConnectionString, settings.DatabaseName) + db, err := NewDB(logger, settings.ConnectionString, settings.DatabaseName) if err != nil { return nil, err } - coll := db.Database.Collection(verificationCodesCollectionName) + coll := db.database.Collection(verificationCodesCollectionName) vcs := &VerificationCodeStorage{coll: coll, timeout: 30 * time.Second} phoneIndexOptions := &options.IndexOptions{} diff --git a/storage/plugin/user.go b/storage/plugin/user.go index 050536a0..33eab9a3 100644 --- a/storage/plugin/user.go +++ b/storage/plugin/user.go @@ -1,6 +1,7 @@ package plugin import ( + "os" "os/exec" "github.com/hashicorp/go-plugin" @@ -18,12 +19,19 @@ func NewUserStorage(settings model.PluginSettings) (model.UserStorage, error) { params = append(params, v) } - client := plugin.NewClient(&plugin.ClientConfig{ + cfg := &plugin.ClientConfig{ HandshakeConfig: shared.Handshake, Plugins: shared.PluginMap, Cmd: exec.Command(settings.Cmd, params...), AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, - }) + } + + if settings.RedirectStd { + cfg.SyncStdout = os.Stdout + cfg.SyncStderr = os.Stderr + } + + client := plugin.NewClient(cfg) // Connect via RPC rpcClient, err := client.Client() diff --git a/storage/redis/session.go b/storage/redis/session.go index 97999131..bb4b009b 100644 --- a/storage/redis/session.go +++ b/storage/redis/session.go @@ -3,22 +3,27 @@ package redis import ( "encoding/json" "io" - "log" + "log/slog" "strings" "time" "github.com/go-redis/redis" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) // RedisSessionStorage is a Redis-backed storage for admin sessions. type RedisSessionStorage struct { + logger *slog.Logger client redis.Cmdable prefix string } // NewSessionStorage creates new Redis session storage. -func NewSessionStorage(settings model.RedisDatabaseSettings) (model.SessionStorage, error) { +func NewSessionStorage( + logger *slog.Logger, + settings model.RedisDatabaseSettings, +) (model.SessionStorage, error) { var addr, password string var db int @@ -59,6 +64,7 @@ func NewSessionStorage(settings model.RedisDatabaseSettings) (model.SessionStora } return &RedisSessionStorage{ + logger: logger, client: client, prefix: p, }, nil @@ -95,7 +101,9 @@ func (r *RedisSessionStorage) DeleteSession(id string) error { key := r.prefix + id count, err := r.client.Del(key).Result() if count == 0 { - log.Println("Tried to delete nonexistent session:", id) + r.logger.Warn("Tried to delete non existent session", + "key", key, + logging.FieldError, err) } return err diff --git a/storage/s3/fs_test.go b/storage/s3/fs_test.go index cdf804d2..c3305025 100644 --- a/storage/s3/fs_test.go +++ b/storage/s3/fs_test.go @@ -40,7 +40,7 @@ func TestNewFSWithS3(t *testing.T) { testFSContent(settings, s3client, t) } -func testFSContent(sts model.FileStorageSettings, s3client *s3.S3, t *testing.T) { +func testFSContent(sts model.FileStorageSettings, _ *s3.S3, t *testing.T) { fss, err := storage.NewFS(sts) if err != nil { t.Fatalf("error creating local fs with error: %v", err) diff --git a/storage/s3/fs_watcher_test.go b/storage/s3/fs_watcher_test.go index dbe3d9c5..9a503d88 100644 --- a/storage/s3/fs_watcher_test.go +++ b/storage/s3/fs_watcher_test.go @@ -7,6 +7,7 @@ import ( "time" "github.com/aws/aws-sdk-go/service/s3" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage" "github.com/stretchr/testify/assert" @@ -40,7 +41,11 @@ func TestNewFSWatcher(t *testing.T) { time.Sleep(time.Second * 1) - watcher := storage.NewFSWatcher(fss, []string{"test1.txt", "test2.txt", "test3.txt"}, time.Second*2) + watcher := storage.NewFSWatcher( + logging.DefaultLogger, + fss, + []string{"test1.txt", "test2.txt", "test3.txt"}, + time.Second*2) watcher.Watch() go func() { diff --git a/storage/s3/key_storage_connection_tester.go b/storage/s3/key_storage_connection_tester.go index abe502c9..8cc0367f 100644 --- a/storage/s3/key_storage_connection_tester.go +++ b/storage/s3/key_storage_connection_tester.go @@ -1,6 +1,7 @@ package s3 import ( + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -16,7 +17,7 @@ func NewKeyStorageConnectionTester(settings model.FileStorageS3) model.Connectio func (ct *KeyStorageConnectionTester) Connect() error { // let's try to load keys from the storage, if we can - it means - ks, err := NewKeyStorage(ct.settings) + ks, err := NewKeyStorage(logging.DefaultLogger, ct.settings) if err != nil { return err } diff --git a/storage/s3/keys.go b/storage/s3/keys.go index d43e7efe..eb621b88 100644 --- a/storage/s3/keys.go +++ b/storage/s3/keys.go @@ -4,7 +4,7 @@ import ( "bytes" "fmt" "io" - "log" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/s3" @@ -14,43 +14,49 @@ import ( // KeyStorage is a wrapper over private key files type KeyStorage struct { - Client *s3.S3 - Bucket string - PrivateKeyPath string + logger *slog.Logger + client *s3.S3 + bucket string + privateKeyPath string } // NewKeyStorage creates and returns new S3-backed key files storage. -func NewKeyStorage(settings model.FileStorageS3) (*KeyStorage, error) { +func NewKeyStorage( + logger *slog.Logger, + settings model.FileStorageS3, +) (*KeyStorage, error) { s3Client, err := NewS3Client(settings.Region, settings.Endpoint) if err != nil { return nil, err } return &KeyStorage{ - Client: s3Client, - Bucket: settings.Bucket, - PrivateKeyPath: settings.Key, + logger: logger, + client: s3Client, + bucket: settings.Bucket, + privateKeyPath: settings.Key, }, nil } // ReplaceKey replaces private key into S3 key storage func (ks *KeyStorage) ReplaceKey(keyPEM []byte) error { - log.Println("Putting new keys to S3...") + ks.logger.Info("Putting new keys to S3...") if keyPEM == nil { - return fmt.Errorf("Cannot insert empty key") + return fmt.Errorf("cannot insert empty key") } - _, err := ks.Client.PutObject(&s3.PutObjectInput{ - Bucket: aws.String(ks.Bucket), - Key: aws.String(ks.PrivateKeyPath), + _, err := ks.client.PutObject(&s3.PutObjectInput{ + Bucket: aws.String(ks.bucket), + Key: aws.String(ks.privateKeyPath), ACL: aws.String("private"), StorageClass: aws.String(s3.ObjectStorageClassStandard), Body: bytes.NewReader(keyPEM), ContentType: aws.String("application/x-pem-file"), }) if err == nil { - log.Printf("Successfully put %s to S3\n", ks.PrivateKeyPath) + ks.logger.Info("Successfully put key to S3", + "path", ks.privateKeyPath) } return nil @@ -59,19 +65,19 @@ func (ks *KeyStorage) ReplaceKey(keyPEM []byte) error { // LoadPrivateKey loads private key from the storage func (ks *KeyStorage) LoadPrivateKey() (interface{}, error) { getKeyInput := &s3.GetObjectInput{ - Bucket: aws.String(ks.Bucket), - Key: aws.String(ks.PrivateKeyPath), + Bucket: aws.String(ks.bucket), + Key: aws.String(ks.privateKeyPath), } - resp, err := ks.Client.GetObject(getKeyInput) + resp, err := ks.client.GetObject(getKeyInput) if err != nil { - return nil, fmt.Errorf("Cannot get %s from S3: %s", ks.PrivateKeyPath, err) + return nil, fmt.Errorf("cannot get %s from S3: %w", ks.privateKeyPath, err) } defer resp.Body.Close() keyData, err := io.ReadAll(resp.Body) if err != nil { - return nil, fmt.Errorf("Cannot decode S3 response: %s", err) + return nil, fmt.Errorf("cannot decode S3 response: %w", err) } privateKey, _, err := jwt.LoadPrivateKeyFromPEMString(string(keyData)) diff --git a/storage/s3/s3_config_storage.go b/storage/s3/s3_config_storage.go index 9d29ba4b..f7ad799f 100644 --- a/storage/s3/s3_config_storage.go +++ b/storage/s3/s3_config_storage.go @@ -3,7 +3,7 @@ package s3 import ( "bytes" "fmt" - "log" + "log/slog" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/s3" @@ -13,6 +13,7 @@ import ( // ConfigurationStorage is a server configuration storage in S3. type ConfigurationStorage struct { + logger *slog.Logger Client *s3.S3 Bucket string ObjectName string @@ -24,19 +25,23 @@ type ConfigurationStorage struct { } // NewConfigurationStorage creates new server config storage in S3. -func NewConfigurationStorage(config model.FileStorageSettings) (*ConfigurationStorage, error) { - log.Println("Loading server configuration from the S3 bucket...") +func NewConfigurationStorage( + logger *slog.Logger, + config model.FileStorageSettings, +) (*ConfigurationStorage, error) { + logger.Info("Loading server configuration from the S3 bucket...") if config.Type != model.FileStorageTypeS3 { - return nil, fmt.Errorf("Configuration file from S3 specifies configuration type %s", config.Type) + return nil, fmt.Errorf("configuration file from S3 specifies configuration type %s", config.Type) } s3client, err := NewS3Client(config.S3.Region, config.S3.Endpoint) if err != nil { - return nil, fmt.Errorf("Cannot initialize S3 client: %s.", err) + return nil, fmt.Errorf("cannot initialize S3 client: %w", err) } cs := &ConfigurationStorage{ + logger: logger, Client: s3client, Bucket: config.S3.Bucket, ObjectName: config.S3.Key, @@ -59,7 +64,7 @@ func (cs *ConfigurationStorage) LoadServerSettings(validate bool) (model.ServerS resp, err := cs.Client.GetObject(getObjInput) if err != nil { - e := fmt.Errorf("Cannot get object from S3: %s", err) + e := fmt.Errorf("cannot get object from S3: %w", err) cs.errors = append(cs.errors, e) return model.ServerSettings{}, cs.errors } @@ -67,7 +72,7 @@ func (cs *ConfigurationStorage) LoadServerSettings(validate bool) (model.ServerS var settings model.ServerSettings if err = yaml.NewDecoder(resp.Body).Decode(&settings); err != nil { - cs.errors = append(cs.errors, fmt.Errorf("Cannot decode S3 response: %s", err)) + cs.errors = append(cs.errors, fmt.Errorf("cannot decode S3 response: %w", err)) return model.ServerSettings{}, cs.errors } @@ -82,11 +87,11 @@ func (cs *ConfigurationStorage) LoadServerSettings(validate bool) (model.ServerS // WriteConfig puts new configuration into the storage. func (cs *ConfigurationStorage) WriteConfig(settings model.ServerSettings) error { - log.Println("Putting new config to S3...") + cs.logger.Info("Putting new config to S3...") valueBytes, err := yaml.Marshal(settings) if err != nil { - return fmt.Errorf("Cannot marshal settings value: %s", err) + return fmt.Errorf("cannot marshal settings value: %w", err) } _, err = cs.Client.PutObject(&s3.PutObjectInput{ @@ -100,13 +105,13 @@ func (cs *ConfigurationStorage) WriteConfig(settings model.ServerSettings) error }) if err == nil { - log.Println("Successfully put new configuration to S3") + cs.logger.Info("Successfully put new configuration to S3") } // Indicate config update. To prevent writing to a closed channel, make a check. go func() { if cs.updateChanClosed { - log.Println("Attempted to write to closed UpdateChan") + cs.logger.Warn("Attempted to write to closed UpdateChan") return } cs.UpdateChan <- struct{}{} diff --git a/storage/s3/s3_storage_test.go b/storage/s3/s3_storage_test.go index 49f112d0..c3f67e87 100644 --- a/storage/s3/s3_storage_test.go +++ b/storage/s3/s3_storage_test.go @@ -7,6 +7,7 @@ import ( "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/service/s3" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" s3s "github.com/madappgang/identifo/v2/storage/s3" "github.com/stretchr/testify/assert" @@ -25,15 +26,17 @@ func TestS3ConfigSource(t *testing.T) { _ = getS3Client(t, ep) putTestFileTOS3(t, awsEndpoint) - c, err := s3s.NewConfigurationStorage(model.FileStorageSettings{ - Type: model.FileStorageTypeS3, - S3: model.FileStorageS3{ - Region: settings.Region, - Bucket: settings.Bucket, - Key: settings.Key, - Endpoint: awsEndpoint, - }, - }) + c, err := s3s.NewConfigurationStorage( + logging.DefaultLogger, + model.FileStorageSettings{ + Type: model.FileStorageTypeS3, + S3: model.FileStorageS3{ + Region: settings.Region, + Bucket: settings.Bucket, + Key: settings.Key, + Endpoint: awsEndpoint, + }, + }) require.NoError(t, err) settings, errs := c.LoadServerSettings(false) require.Empty(t, errs) diff --git a/storage/s3/s3_test.go b/storage/s3/s3_test.go index f7065c52..6884ca70 100644 --- a/storage/s3/s3_test.go +++ b/storage/s3/s3_test.go @@ -46,7 +46,7 @@ func getS3Client(t *testing.T, endpoint string) *s3.S3 { return s3client } -func uploadS3File(t *testing.T, s3client *s3.S3, s model.FileStorageS3, key string) { +func uploadS3File(t *testing.T, s3client *s3.S3, _ model.FileStorageS3, key string) { newFilecontent := []byte(fmt.Sprintf("This content has been changed at %v", time.Now().Unix())) input := &s3.PutObjectInput{ Bucket: aws.String(settings.Bucket), diff --git a/storage/session.go b/storage/session.go index bc473be6..33ecb3ce 100644 --- a/storage/session.go +++ b/storage/session.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/dynamodb" @@ -10,14 +11,17 @@ import ( ) // NewSessionStorage creates new sessions storage from settings -func NewSessionStorage(settings model.SessionStorageSettings) (model.SessionStorage, error) { +func NewSessionStorage( + logger *slog.Logger, + settings model.SessionStorageSettings, +) (model.SessionStorage, error) { switch settings.Type { case model.SessionStorageRedis: - return redis.NewSessionStorage(settings.Redis) + return redis.NewSessionStorage(logger, settings.Redis) case model.SessionStorageMem: return mem.NewSessionStorage(), nil case model.SessionStorageDynamoDB: - return dynamodb.NewSessionStorage(settings.Dynamo) + return dynamodb.NewSessionStorage(logger, settings.Dynamo) default: return nil, fmt.Errorf("session storage type is not supported") } diff --git a/storage/token.go b/storage/token.go index e95e00a0..0f51dd7a 100644 --- a/storage/token.go +++ b/storage/token.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -11,14 +12,16 @@ import ( ) // NewTokenStorage creates new tokens storage from settings -func NewTokenStorage(settings model.DatabaseSettings) (model.TokenStorage, error) { +func NewTokenStorage( + logger *slog.Logger, + settings model.DatabaseSettings) (model.TokenStorage, error) { switch settings.Type { case model.DBTypeBoltDB: - return boltdb.NewTokenStorage(settings.BoltDB) + return boltdb.NewTokenStorage(logger, settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewTokenStorage(settings.Mongo) + return mongo.NewTokenStorage(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewTokenStorage(settings.Dynamo) + return dynamodb.NewTokenStorage(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: diff --git a/storage/token_blacklist.go b/storage/token_blacklist.go index fe8aab49..766c77d7 100644 --- a/storage/token_blacklist.go +++ b/storage/token_blacklist.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -11,14 +12,17 @@ import ( ) // NewTokenBlacklistStorage creates new tokens blacklist storage from settings -func NewTokenBlacklistStorage(settings model.DatabaseSettings) (model.TokenBlacklist, error) { +func NewTokenBlacklistStorage( + logger *slog.Logger, + settings model.DatabaseSettings, +) (model.TokenBlacklist, error) { switch settings.Type { case model.DBTypeBoltDB: - return boltdb.NewTokenBlacklist(settings.BoltDB) + return boltdb.NewTokenBlacklist(logger, settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewTokenBlacklist(settings.Mongo) + return mongo.NewTokenBlacklist(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewTokenBlacklist(settings.Dynamo) + return dynamodb.NewTokenBlacklist(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: diff --git a/storage/user.go b/storage/user.go index 115eaa0e..a9e6b45a 100644 --- a/storage/user.go +++ b/storage/user.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -13,14 +14,16 @@ import ( ) // NewUserStorage creates new users storage from settings -func NewUserStorage(settings model.DatabaseSettings) (model.UserStorage, error) { +func NewUserStorage( + logger *slog.Logger, + settings model.DatabaseSettings) (model.UserStorage, error) { switch settings.Type { case model.DBTypeBoltDB: - return boltdb.NewUserStorage(settings.BoltDB) + return boltdb.NewUserStorage(logger, settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewUserStorage(settings.Mongo) + return mongo.NewUserStorage(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewUserStorage(settings.Dynamo) + return dynamodb.NewUserStorage(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: diff --git a/storage/verification_codes.go b/storage/verification_codes.go index b4337a73..52668e6b 100644 --- a/storage/verification_codes.go +++ b/storage/verification_codes.go @@ -2,6 +2,7 @@ package storage import ( "fmt" + "log/slog" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/storage/boltdb" @@ -11,14 +12,16 @@ import ( ) // NewVerificationCodesStorage creates new verification codes storage from settings -func NewVerificationCodesStorage(settings model.DatabaseSettings) (model.VerificationCodeStorage, error) { +func NewVerificationCodesStorage( + logger *slog.Logger, + settings model.DatabaseSettings) (model.VerificationCodeStorage, error) { switch settings.Type { case model.DBTypeBoltDB: - return boltdb.NewVerificationCodeStorage(settings.BoltDB) + return boltdb.NewVerificationCodeStorage(logger, settings.BoltDB) case model.DBTypeMongoDB: - return mongo.NewVerificationCodeStorage(settings.Mongo) + return mongo.NewVerificationCodeStorage(logger, settings.Mongo) case model.DBTypeDynamoDB: - return dynamodb.NewVerificationCodeStorage(settings.Dynamo) + return dynamodb.NewVerificationCodeStorage(logger, settings.Dynamo) case model.DBTypeFake: fallthrough case model.DBTypeMem: diff --git a/user_payload_provider/plugin/provider.go b/user_payload_provider/plugin/provider.go index 75ace896..29ac4d59 100644 --- a/user_payload_provider/plugin/provider.go +++ b/user_payload_provider/plugin/provider.go @@ -1,6 +1,7 @@ package plugin import ( + "os" "os/exec" "time" @@ -19,12 +20,20 @@ func NewTokenPayloadProvider(settings model.PluginSettings, timeout time.Duratio params = append(params, v) } - client := plugin.NewClient(&plugin.ClientConfig{ + cfg := &plugin.ClientConfig{ + SyncStdout: os.Stdout, HandshakeConfig: shared.Handshake, Plugins: shared.PluginMap, Cmd: exec.Command(settings.Cmd, params...), AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC}, - }) + } + + if settings.RedirectStd { + cfg.SyncStdout = os.Stdout + cfg.SyncStderr = os.Stderr + } + + client := plugin.NewClient(cfg) // Connect via RPC rpcClient, err := client.Client() diff --git a/web/admin/apps.go b/web/admin/apps.go index 72a348f1..523144bb 100644 --- a/web/admin/apps.go +++ b/web/admin/apps.go @@ -8,6 +8,7 @@ import ( "net/http" "strings" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -96,7 +97,7 @@ func (ar *Router) UpdateApp() http.HandlerFunc { return } if !isBase64(ad.Secret) { - err := fmt.Errorf("Expecting appsecret to be base64 encoded") + err := fmt.Errorf("Expecting app secret to be base64 encoded") ar.Error(w, err, http.StatusBadRequest, err.Error()) return } @@ -108,10 +109,13 @@ func (ar *Router) UpdateApp() http.HandlerFunc { } if err = ar.updateAllowedOrigins(); err != nil { - ar.logger.Printf("Error occurred during updating allowed origins for App %s, error: %v", appID, err) + ar.logger.Error("Error occurred during updating allowed origins for App", + "appId", appID, + "error", err) } - ar.logger.Printf("App %s updated", appID) + ar.logger.Info("App updated", + "appId", appID) ar.ServeJSON(w, http.StatusOK, app) } @@ -126,7 +130,7 @@ func (ar *Router) DeleteApp() http.HandlerFunc { return } - ar.logger.Printf("App %s deleted", appID) + ar.logger.Info("App deleted", "appId", appID) ar.ServeJSON(w, http.StatusOK, nil) } @@ -145,7 +149,9 @@ func (ar *Router) DeleteAllApps() http.HandlerFunc { err := ar.server.Storages().App.DeleteApp(a.ID) if err != nil { errs = append(errs, err) - ar.logger.Printf("Error deleting app: %s, error: %s. Ignoring and moving next.", a.ID, err) + ar.logger.Error("Error deleting app. Ignoring and moving next.", + logging.FieldAppID, a.ID, + logging.FieldError, err) } } if len(errs) > 0 { diff --git a/web/admin/logout.go b/web/admin/logout.go index 84b2a1cc..0c89e4df 100644 --- a/web/admin/logout.go +++ b/web/admin/logout.go @@ -20,7 +20,7 @@ func (ar *Router) Logout() http.HandlerFunc { if err != nil { switch err { case http.ErrNoCookie: - ar.logger.Println("No cookie") + ar.logger.Warn("No cookie during logout") ar.ServeJSON(w, http.StatusOK, nil) default: ar.Error(w, err, http.StatusInternalServerError, "") diff --git a/web/admin/middleware.go b/web/admin/middleware.go index 66d8a67b..2de320ac 100644 --- a/web/admin/middleware.go +++ b/web/admin/middleware.go @@ -5,6 +5,7 @@ import ( "strings" "time" + "github.com/madappgang/identifo/v2/logging" "github.com/urfave/negroni" ) @@ -57,7 +58,8 @@ func (ar *Router) isLoggedIn(w http.ResponseWriter, r *http.Request) bool { func (ar *Router) prolongSession(w http.ResponseWriter, sessionID string) { if err := ar.server.Services().Session.ProlongSession(sessionID); err != nil { - ar.logger.Println("Error prolonging session:", err) + ar.logger.Error("Error prolonging session", + logging.FieldError, err) return } c := &http.Cookie{ diff --git a/web/admin/router.go b/web/admin/router.go index 96147e24..6958572b 100644 --- a/web/admin/router.go +++ b/web/admin/router.go @@ -2,12 +2,12 @@ package admin import ( "encoding/json" - "log" + "log/slog" "net/http" "net/url" - "os" "github.com/gorilla/mux" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/middleware" "github.com/rs/cors" @@ -19,7 +19,7 @@ type Router struct { server model.Server middleware *negroni.Negroni cors *cors.Cors - logger *log.Logger + logger *slog.Logger router *mux.Router RedirectURL string PathPrefix string @@ -30,7 +30,7 @@ type Router struct { type RouterSettings struct { Server model.Server - Logger *log.Logger + Logger *slog.Logger Host *url.URL Prefix string Cors *cors.Cors @@ -41,8 +41,10 @@ type RouterSettings struct { // NewRouter creates and initializes new admin router. func NewRouter(settings RouterSettings) (model.Router, error) { ar := Router{ - server: settings.Server, - middleware: negroni.New(middleware.NewNegroniLogger("ADMIN_API"), negroni.NewRecovery()), + server: settings.Server, + middleware: negroni.New( + middleware.NewNegroniLogger("ADMIN_API"), + negroni.NewRecovery()), router: mux.NewRouter(), Host: settings.Host, PathPrefix: settings.Prefix, @@ -53,7 +55,8 @@ func NewRouter(settings RouterSettings) (model.Router, error) { } if settings.Logger == nil { - ar.logger = log.New(os.Stdout, "ADMIN_ROUTER: ", log.Ldate|log.Ltime|log.Lshortfile) + ar.logger = logging.NewDefaultLogger(). + With(logging.FieldComponent, "ADMIN_ROUTER") } ar.middleware.Use(ar.RemoveTrailingSlash()) @@ -79,7 +82,9 @@ func (ar *Router) Error(w http.ResponseWriter, err error, code int, userInfo str } // Log error. - ar.logger.Printf("admin error: %v (code=%d)", err, code) + ar.logger.Error("admin error", + logging.FieldError, err, + "errorCode", code) w.Header().Set("Content-Type", "application/json") w.WriteHeader(code) @@ -89,7 +94,8 @@ func (ar *Router) Error(w http.ResponseWriter, err error, code int, userInfo str Code: code, }) if encodeErr != nil { - ar.logger.Printf("error writing http response: %s", err) + ar.logger.Error("error writing http response", + logging.FieldError, encodeErr) } } @@ -110,6 +116,7 @@ func (ar *Router) ServeJSON(w http.ResponseWriter, code int, v interface{}) { w.Header().Set("Content-Type", "application/json") w.WriteHeader(code) if _, err = w.Write(data); err != nil { - log.Printf("error writing http response: %s", err) + ar.logger.Error("error writing http response", + logging.FieldError, err) } } diff --git a/web/admin/settings.go b/web/admin/settings.go index f33d6cb9..d585596d 100644 --- a/web/admin/settings.go +++ b/web/admin/settings.go @@ -4,6 +4,7 @@ import ( "fmt" "net/http" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -62,7 +63,8 @@ func (ar *Router) UpdateSettings() http.HandlerFunc { } if err := ar.server.Storages().Config.WriteConfig(merged); err != nil { - ar.logger.Println("Cannot insert new settings into configuration storage:", err) + ar.logger.Error("Cannot insert new settings into configuration storage", + logging.FieldError, err) ar.Error(w, fmt.Errorf("error saving new config: %v", err), http.StatusInternalServerError, "") return } @@ -70,7 +72,7 @@ func (ar *Router) UpdateSettings() http.HandlerFunc { // if the config storage is not supporting instant reloading - let's force restart it if ar.forceRestart != nil && ar.server.Storages().Config.ForceReloadOnWriteConfig() { go func() { - ar.logger.Println("sending server restart") + ar.logger.Info("sending server restart") ar.forceRestart <- true }() } diff --git a/web/admin/test_connection.go b/web/admin/test_connection.go index 1a825a31..d4e05431 100644 --- a/web/admin/test_connection.go +++ b/web/admin/test_connection.go @@ -28,10 +28,8 @@ func (ar *Router) TestConnection() http.HandlerFunc { } err = tester.Connect() if err != nil { - if err != nil { - ar.Error(w, fmt.Errorf("connection error: %v", err), http.StatusBadRequest, "") - return - } + ar.Error(w, fmt.Errorf("connection error: %v", err), http.StatusBadRequest, "") + return } ar.ServeJSON(w, http.StatusOK, tc) } diff --git a/web/admin/users.go b/web/admin/users.go index d3b09faa..702387fa 100644 --- a/web/admin/users.go +++ b/web/admin/users.go @@ -6,6 +6,7 @@ import ( "net/url" "strings" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -186,7 +187,8 @@ func (ar *Router) UpdateUser() http.HandlerFunc { return } - ar.logger.Printf("User %s updated", userID) + ar.logger.Info("User updated", + logging.FieldUserID, userID) user = user.Sanitized() ar.ServeJSON(w, http.StatusOK, user) @@ -202,7 +204,8 @@ func (ar *Router) DeleteUser() http.HandlerFunc { return } - ar.logger.Printf("User %s deleted", userID) + ar.logger.Info("User deleted", + logging.FieldUserID, userID) ar.ServeJSON(w, http.StatusOK, nil) } } diff --git a/web/api/2fa.go b/web/api/2fa.go index d55a2a42..e7467860 100644 --- a/web/api/2fa.go +++ b/web/api/2fa.go @@ -11,6 +11,7 @@ import ( ijwt "github.com/madappgang/identifo/v2/jwt" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/middleware" qrcode "github.com/skip2/go-qrcode" @@ -289,7 +290,8 @@ func (ar *Router) FinalizeTFA() http.HandlerFunc { // Blacklist old access token. if err := ar.server.Storages().Blocklist.Add(oldAccessTokenString); err != nil { - ar.logger.Printf("Cannot blacklist old access token: %s\n", err) + ar.logger.Error("Cannot blacklist old access token", + logging.FieldError, err) } user = user.Sanitized() diff --git a/web/api/appsecret.go b/web/api/appsecret.go index f798632f..c894e41b 100644 --- a/web/api/appsecret.go +++ b/web/api/appsecret.go @@ -42,7 +42,8 @@ func (ar *Router) SignatureHandler() negroni.HandlerFunc { if r.Method == "GET" { body = []byte(r.URL.RequestURI() + t) - ar.logger.Println("RequestURI to sign:", r.URL.RequestURI()+t, "(GET request)") + ar.logger.Info("RequestURI to sign (GET request)", + "uriData", r.URL.RequestURI()+t) } else { // Extract body. b, err := io.ReadAll(r.Body) @@ -50,10 +51,13 @@ func (ar *Router) SignatureHandler() negroni.HandlerFunc { ar.Error(rw, locale, http.StatusBadRequest, l.ErrorAPIRequestBodyInvalidError, err) return } + if len(b) == 0 { b = []byte(r.URL.RequestURI() + t) - ar.logger.Println("RequestURI to sign:", r.URL.RequestURI()+t, "(POST request)") + ar.logger.Info("RequestURI to sign (POST request)", + "uriData", r.URL.RequestURI()+t) } + body = b } @@ -106,10 +110,10 @@ func validateBodySignature(body, reqMAC, secret []byte) error { if _, err := mac.Write(body); err != nil { return err } + expectedMAC := mac.Sum(nil) if !hmac.Equal(reqMAC, expectedMAC) { - // fmt.Printf("Error validation signature, expecting: %v, got: %v\n", hex.EncodeToString(expectedMAC), hex.EncodeToString(reqMAC)) - return errors.New("Request hmac is not equal to expected. ") + return errors.New("request hmac is not equal to expected. ") } return nil } diff --git a/web/api/dump_request.go b/web/api/dump_request.go deleted file mode 100644 index 84130d83..00000000 --- a/web/api/dump_request.go +++ /dev/null @@ -1,20 +0,0 @@ -package api - -import ( - "net/http" - "net/http/httputil" - - "github.com/urfave/negroni" -) - -// DumpRequest logs the request. -func (ar *Router) DumpRequest() negroni.HandlerFunc { - return func(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) { - dump, err := httputil.DumpRequest(r, true) - if err != nil { - ar.logger.Println("Error dumping request:", err) - } - ar.logger.Printf("Request: %s\n", string(dump)) - next(rw, r) - } -} diff --git a/web/api/federated_login.go b/web/api/federated_login.go index 3da12c54..9bfa6381 100644 --- a/web/api/federated_login.go +++ b/web/api/federated_login.go @@ -8,7 +8,6 @@ import ( "errors" "fmt" "io" - "log" "net/http" "net/url" "reflect" @@ -16,6 +15,7 @@ import ( "github.com/gorilla/sessions" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/authorization" "github.com/madappgang/identifo/v2/web/middleware" @@ -115,7 +115,7 @@ func (ar *Router) FederatedLogin() http.HandlerFunc { return } - log.Println("federated auth url", url) + ar.logger.Info("federated auth url", logging.FieldURL, url) http.Redirect(w, r, url, http.StatusTemporaryRedirect) } @@ -212,6 +212,8 @@ func (ar *Router) FederatedLoginComplete() http.HandlerFunc { authResult.CallbackUrl = fsess.CallbackUrl authResult.Scopes = fsess.Scopes + ar.journal(JournalOperationFederatedLogin, user.ID, app.ID, r) + ar.ServeJSON(w, locale, http.StatusOK, authResult) } } @@ -252,7 +254,7 @@ as either "provider" */ func (ar *Router) GetAuthURL(res http.ResponseWriter, req *http.Request) (string, error) { if !keySet && defaultStore == Store { - fmt.Println("goth/gothic: no SESSION_SECRET environment variable is set. The default cookie store is not available and any calls will fail. Ignore this warning if you are using a different store.") + ar.logger.Info("goth/gothic: no SESSION_SECRET environment variable is set. The default cookie store is not available and any calls will fail. Ignore this warning if you are using a different store.") } providerName := req.URL.Query().Get("provider") @@ -318,7 +320,7 @@ See https://github.com/markbates/goth/examples/main.go to see this in action. */ func (ar *Router) CompleteUserAuth(res http.ResponseWriter, req *http.Request) (goth.User, error) { if !keySet && defaultStore == Store { - fmt.Println("goth/gothic: no SESSION_SECRET environment variable is set. The default cookie store is not available and any calls will fail. Ignore this warning if you are using a different store.") + ar.logger.Info("goth/gothic: no SESSION_SECRET environment variable is set. The default cookie store is not available and any calls will fail. Ignore this warning if you are using a different store.") } providerName := req.URL.Query().Get("provider") diff --git a/web/api/federated_oidc_login.go b/web/api/federated_oidc_login.go index 55755bd7..ff2c116e 100644 --- a/web/api/federated_oidc_login.go +++ b/web/api/federated_oidc_login.go @@ -4,13 +4,12 @@ import ( "context" "errors" "fmt" - "log" "net/http" - "net/url" "sync" "github.com/coreos/go-oidc/v3/oidc" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/authorization" "github.com/madappgang/identifo/v2/web/middleware" @@ -250,6 +249,8 @@ func (ar *Router) OIDCLoginComplete(useSession bool) http.HandlerFunc { authResult.Scopes = requestedScopes authResult.ProviderData = *providerData + ar.journal(JournalOperationOIDCLogin, user.ID, app.ID, r) + ar.ServeJSON(w, locale, http.StatusOK, authResult) } } @@ -268,20 +269,6 @@ func mapScopes(m map[string]string, scopes []string) []string { return result } -func makeRedirectURL(redirect string, app model.AppData) (string, error) { - u, err := url.Parse(redirect) - if err != nil { - return "", err - } - - q := u.Query() - q.Set("appId", app.ID) - - u.RawQuery = q.Encode() - - return u.String(), nil -} - func extractField(data map[string]any, key string) string { val := data[key] @@ -318,7 +305,8 @@ func (ar *Router) completeOIDCAuth( authCode := r.URL.Query().Get("code") if len(authCode) == 0 { - log.Println("failed ot authorize user with OIDC: no code in response", r.URL.Query()) + ar.logger.Info("failed to authorize user with OIDC: no code in response", + logging.FieldURL, r.URL.Query()) return nil, nil, nil, "", NewLocalizedError(http.StatusBadRequest, locale, l.ErrorFederatedCodeError) } @@ -366,7 +354,9 @@ func (ar *Router) completeOIDCAuth( providerScope, ok := providerScopeVal.(string) if !ok { - ar.logger.Printf("oidc returned scope is not string but %T %+v", providerScope, providerScope) + ar.logger.Warn("oidc returned scope is not string", + "scopeType", fmt.Sprintf("%T", providerScopeVal), + "scopeValue", fmt.Sprintf("%+v", providerScopeVal)) } // Extract the ID Token from OAuth2 token. @@ -407,7 +397,7 @@ func (ar *Router) tryFindFederatedUser(provider, fedUserID, email string) (model } if !errors.Is(err, model.ErrUserNotFound) { - return model.User{}, fmt.Errorf("can not find user by federated ID: %w", err) + return model.User{}, fmt.Errorf("cannot find user by federated ID: %w", err) } } @@ -424,7 +414,10 @@ func (ar *Router) tryFindFederatedUser(provider, fedUserID, email string) (model _, uerr := us.UpdateUser(user.ID, user) if uerr != nil { - log.Printf("can not update user %s with federated id: %v\n", email, uerr) + ar.logger.Error("cannot update user with federated id", + logging.FieldEmail, email, + "fedreatedID", fedUserID, + logging.FieldError, uerr) } return user, nil diff --git a/web/api/federated_oidc_login_v2_test.go b/web/api/federated_oidc_login_v2_test.go index e8a55f00..866ac99f 100644 --- a/web/api/federated_oidc_login_v2_test.go +++ b/web/api/federated_oidc_login_v2_test.go @@ -12,73 +12,6 @@ import ( "github.com/stretchr/testify/require" ) -// var testApp = model.AppData{ -// ID: "test_app", -// Active: true, -// Type: model.Web, -// OIDCSettings: model.OIDCSettings{ -// ProviderName: "test", -// ClientID: "test", -// ClientSecret: "test", -// EmailClaimField: "email", -// }, -// } - -// // test environment -// var ( -// testRouter *api.Router -// testServer model.Server -// oidcServer *httptest.Server -// ) - -// type testConfig struct { -// model.ConfigurationStorage -// } - -// var testServerSettings = model.DefaultServerSettings - -// func (tc testConfig) LoadServerSettings(validate bool) (model.ServerSettings, []error) { -// testServerSettings.KeyStorage.Local.Path = "../../jwt/test_artifacts/private.pem" -// testServerSettings.Login.LoginWith.FederatedOIDC = true -// return testServerSettings, nil -// } - -// func (tc testConfig) LoadedSettings() *model.ServerSettings { -// return &testServerSettings -// } - -// func init() { -// var err error - -// rc := make(chan bool, 1) -// testServer, err = config.NewServer(testConfig{}, rc) -// if err != nil { -// panic(err) -// } - -// rs := api.RouterSettings{ -// LoginWith: model.LoginWith{ -// FederatedOIDC: true, -// }, -// Server: testServer, -// Cors: cors.New(model.DefaultCors), -// } - -// testRouter, err = api.NewRouter(rs) -// if err != nil { -// panic(err) -// } - -// oidcServer, _ = testOIDCServer() -// } - -// func testContext(app model.AppData) context.Context { -// ctx := context.Background() -// ctx = context.WithValue(ctx, model.AppDataContextKey, app) - -// return ctx -// } - func Test_Router_OIDCLoginV2_Redirect(t *testing.T) { testApp.OIDCSettings.ProviderURL = oidcServer.URL ctx := testContext(testApp) diff --git a/web/api/hello.go b/web/api/hello.go index 81c72d84..7181afac 100644 --- a/web/api/hello.go +++ b/web/api/hello.go @@ -15,7 +15,8 @@ func (ar *Router) HandleHello() http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { locale := r.Header.Get("Accept-Language") - ar.logger.Println("trace Hello handler") + ar.logger.Debug("trace Hello handler") + hello := helloResponse{ Answer: "Hello, my name is Identifo", Date: time.Now(), @@ -33,7 +34,8 @@ func (ar *Router) HandlePing(w http.ResponseWriter, r *http.Request) { locale := r.Header.Get("Accept-Language") - ar.logger.Println("trace pong handler") + ar.logger.Debug("trace pong handler") + pong := pongResponse{ Message: "Pong!", Date: time.Now(), diff --git a/web/api/impersonate_as.go b/web/api/impersonate_as.go index c7316e74..cab6c647 100644 --- a/web/api/impersonate_as.go +++ b/web/api/impersonate_as.go @@ -3,10 +3,10 @@ package api import ( "context" "errors" - "log" "net/http" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/middleware" ) @@ -34,7 +34,9 @@ func (ar *Router) ImpersonateAs() http.HandlerFunc { return } - log.Println("admin for impersonation", adminUser.ID, adminUser.Scopes) + ar.logger.Info("admin for impersonation", + logging.FieldUserID, adminUser.ID, + "scopes", adminUser.Scopes) d := impersonateData{} if ar.MustParseJSON(w, r, &d) != nil { @@ -49,7 +51,8 @@ func (ar *Router) ImpersonateAs() http.HandlerFunc { ok, err := ar.checkImpersonationPermissions(ctx, app, adminUser, user) if err != nil { - log.Printf("can not check impersonation: %v\n", err) + ar.logger.Error("cannot check impersonation", + logging.FieldError, err) ar.Error(w, locale, http.StatusForbidden, l.ErrorAPIImpersonationForbidden) return } diff --git a/web/api/journal.go b/web/api/journal.go new file mode 100644 index 00000000..13a571b7 --- /dev/null +++ b/web/api/journal.go @@ -0,0 +1,29 @@ +package api + +import ( + "net/http" + + "github.com/madappgang/identifo/v2/logging" +) + +type JournalOperation string + +const ( + JournalOperationLoginWithPassword JournalOperation = "login_with_password" + JournalOperationLoginWithPhone JournalOperation = "login_with_phone" + JournalOperationRefreshToken JournalOperation = "refresh_token" + JournalOperationOIDCLogin JournalOperation = "oidc_login" + JournalOperationFederatedLogin JournalOperation = "federated_login" +) + +func (ar *Router) journal( + op JournalOperation, + userID, appID string, + req *http.Request, +) { + ar.logger.Info(string(op), + logging.FieldComponent, "journal", + logging.FieldUserID, userID, + logging.FieldAppID, appID, + "device", req.UserAgent()) +} diff --git a/web/api/login.go b/web/api/login.go index 760f909d..0c3d0080 100644 --- a/web/api/login.go +++ b/web/api/login.go @@ -7,6 +7,7 @@ import ( "time" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" pphttp "github.com/madappgang/identifo/v2/user_payload_provider/http" "github.com/madappgang/identifo/v2/user_payload_provider/plugin" @@ -125,14 +126,16 @@ func (ar *Router) checkSupportedWays(l login) error { // LoginWithPassword logs user in with email and password. func (ar *Router) LoginWithPassword() http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { + var err error + locale := r.Header.Get("Accept-Language") ld := loginData{} - if ar.MustParseJSON(w, r, &ld) != nil { + if err = ar.MustParseJSON(w, r, &ld); err != nil { return } - if err := ld.validate(); err != nil { + if err = ld.validate(); err != nil { ar.Error(w, locale, http.StatusBadRequest, l.ErrorAPIRequestBodyInvalidError, err) return } @@ -142,7 +145,6 @@ func (ar *Router) LoginWithPassword() http.HandlerFunc { return } - var err error user := model.User{} if len(ld.Email) > 0 { @@ -188,6 +190,8 @@ func (ar *Router) LoginWithPassword() http.HandlerFunc { return } + ar.journal(JournalOperationLoginWithPassword, user.ID, app.ID, r) + ar.ServeJSON(w, locale, http.StatusOK, authResult) } } @@ -288,8 +292,9 @@ func (ar *Router) getTokenPayloadService(app model.AppData) (model.TokenPayloadP case model.TokenPayloadServicePlugin: ps, err = plugin.NewTokenPayloadProvider( model.PluginSettings{ - Cmd: app.TokenPayloadServicePluginSettings.Cmd, - Params: app.TokenPayloadServicePluginSettings.Params, + Cmd: app.TokenPayloadServicePluginSettings.Cmd, + Params: app.TokenPayloadServicePluginSettings.Params, + RedirectStd: app.TokenPayloadServicePluginSettings.RedirectStd, }, app.TokenPayloadServicePluginSettings.ClientTimeout) } @@ -320,7 +325,8 @@ func (ar *Router) loginUser(user model.User, scopes []string, app model.AppData, refresh, err := ar.server.Services().Token.NewRefreshToken(user, scopes, app) if err != nil { - ar.logger.Println(err) + ar.logger.Error("Failed to create refresh token", + logging.FieldError, err) return accessTokenString, "", nil } refreshTokenString, err := ar.server.Services().Token.String(refresh) diff --git a/web/api/logout.go b/web/api/logout.go index bb1f6715..0f77979d 100644 --- a/web/api/logout.go +++ b/web/api/logout.go @@ -5,6 +5,7 @@ import ( "net/http" jwt "github.com/golang-jwt/jwt/v4" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -22,15 +23,17 @@ func (ar *Router) Logout() http.HandlerFunc { accessTokenBytes, ok := r.Context().Value(model.TokenRawContextKey).([]byte) if !ok { - ar.logger.Println("Cannot fetch access token bytes from context") + ar.logger.Warn("Cannot fetch access token bytes from context") ar.ServeJSON(w, locale, http.StatusNoContent, nil) return } + accessTokenString := string(accessTokenBytes) // Blacklist current access token. if err := ar.server.Storages().Blocklist.Add(accessTokenString); err != nil { - ar.logger.Printf("Cannot blacklist access token: %s\n", err) + ar.logger.Error("Cannot blacklist access token", + logging.FieldError, err) } if r.Body == http.NoBody { @@ -45,14 +48,16 @@ func (ar *Router) Logout() http.HandlerFunc { // Revoke refresh token, if present. if err := ar.revokeRefreshToken(d.RefreshToken, accessTokenString); err != nil { - ar.logger.Printf("Cannot revoke refresh token: %s\n", err) + ar.logger.Error("Cannot revoke refresh token", + logging.FieldError, err) } // Detach device token, if present. if len(d.DeviceToken) > 0 { // TODO: check for ownership when device tokens are supported. if err := ar.server.Storages().User.DetachDeviceToken(d.DeviceToken); err != nil { - ar.logger.Println("Cannot detach device token") + ar.logger.Error("Cannot detach device token", + logging.FieldError, err) } } diff --git a/web/api/phone_login.go b/web/api/phone_login.go index 0d275a41..b00a0ca0 100644 --- a/web/api/phone_login.go +++ b/web/api/phone_login.go @@ -172,6 +172,9 @@ func (ar *Router) PhoneLogin() http.HandlerFunc { } ar.server.Storages().User.UpdateLoginMetadata(user.ID) + + ar.journal(JournalOperationLoginWithPhone, user.ID, app.ID, r) + ar.ServeJSON(w, locale, http.StatusOK, result) } } diff --git a/web/api/refresh_token.go b/web/api/refresh_token.go index ebde6492..47be245a 100644 --- a/web/api/refresh_token.go +++ b/web/api/refresh_token.go @@ -5,6 +5,7 @@ import ( "net/http" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/middleware" ) @@ -84,6 +85,8 @@ func (ar *Router) RefreshTokens() http.HandlerFunc { RefreshToken: newRefreshTokenString, } + ar.journal(JournalOperationRefreshToken, oldRefreshToken.Subject(), app.ID, r) + ar.ServeJSON(w, locale, http.StatusOK, result) } } @@ -118,10 +121,14 @@ func (ar *Router) issueNewRefreshToken(oldRefreshTokenString string, scopes []st func (ar *Router) invalidateOldRefreshToken(oldRefreshTokenString string) { if err := ar.server.Storages().Token.DeleteToken(oldRefreshTokenString); err != nil { - ar.logger.Println("Cannot delete old refresh token from token storage:", err) + ar.logger.Error("Cannot delete old refresh token from token storage", + logging.FieldError, err) } + if err := ar.server.Storages().Blocklist.Add(oldRefreshTokenString); err != nil { - ar.logger.Println("Cannot blacklist old refresh token:", err) + ar.logger.Error("Cannot blacklist old refresh token", + logging.FieldError, err) } - ar.logger.Println("Old refresh token successfully invalidated") + + ar.logger.Info("Old refresh token successfully invalidated") } diff --git a/web/api/reset_password.go b/web/api/reset_password.go index 7a31407c..5eb748d0 100644 --- a/web/api/reset_password.go +++ b/web/api/reset_password.go @@ -39,7 +39,8 @@ func (ar *Router) RequestResetPassword() http.HandlerFunc { user, err := ar.server.Storages().User.UserByEmail(d.Email) if err == model.ErrUserNotFound { // return ok, but there is no user - ar.logger.Printf("Trying to reset password for the user, which is not exists: %s. Sending back ok to user for security reason.", d.Email) + ar.logger.Info("Trying to reset password for the user, which is not exists. Sending back ok to user for security reason.", + "email", d.Email) result := map[string]string{"result": "ok"} ar.ServeJSON(w, locale, http.StatusOK, result) return diff --git a/web/api/router.go b/web/api/router.go index ad37d354..fa7edda1 100644 --- a/web/api/router.go +++ b/web/api/router.go @@ -3,15 +3,15 @@ package api import ( "encoding/json" "fmt" - "log" + "log/slog" "net/http" "net/url" - "os" "runtime" "sync" "github.com/gorilla/mux" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/authorization" "github.com/rs/cors" @@ -21,7 +21,7 @@ import ( type Router struct { server model.Server cors *cors.Cors - logger *log.Logger + logger *slog.Logger router *mux.Router tfaType model.TFAType tfaResendTimeout int @@ -40,7 +40,7 @@ type Router struct { type RouterSettings struct { Server model.Server - Logger *log.Logger + Logger *slog.Logger LoggerSettings model.LoggerSettings Authorizer *authorization.Authorizer Host *url.URL @@ -73,7 +73,7 @@ func NewRouter(settings RouterSettings) (*Router, error) { // setup logger to stdout. if settings.Logger == nil { - ar.logger = log.New(os.Stdout, "API_ROUTER: ", log.Ldate|log.Ltime|log.Lshortfile) + ar.logger = logging.NewDefaultLogger().With(logging.FieldComponent, "API_ROUTER") } else { ar.logger = settings.Logger } @@ -102,7 +102,8 @@ func (ar *Router) ServeJSON(w http.ResponseWriter, locale string, status int, v w.Header().Set("Content-Type", "application/json") w.WriteHeader(status) if _, err = w.Write(data); err != nil { - log.Printf("error writing http response: %s", err) + ar.logger.Error("error writing http response", + logging.FieldError, err) } } @@ -127,8 +128,6 @@ func (e *LocalizedError) Error() string { } func (ar *Router) ErrorResponse(w http.ResponseWriter, err error) { - ar.logger.Printf("api error: %v", err) - switch e := err.(type) { case *LocalizedError: ar.error(w, 3, e.locale, e.status, e.errID, e.details...) @@ -162,8 +161,11 @@ func (ar *Router) error(w http.ResponseWriter, callerDepth int, locale string, s } message := ar.ls.SL(locale, errID, details...) - // Log error. - ar.logger.Printf("api error: %v (status=%v). Details: %v. Where: %v:%d.", errID, status, message, file, no) + ar.logger.Error("api error", + logging.FieldErrorID, errID, + "status", status, + "details", message, + "where", fmt.Sprintf("%v:%d", file, no)) // Write generic error response. w.Header().Set("Content-Type", "application/json") @@ -182,6 +184,7 @@ func (ar *Router) error(w http.ResponseWriter, callerDepth int, locale string, s encodeErr := json.NewEncoder(w).Encode(resp) if encodeErr != nil { - ar.logger.Printf("error writing http response: %s", errID) + ar.logger.Error("error writing http response", + logging.FieldError, encodeErr) } } diff --git a/web/api/utils.go b/web/api/utils.go index c5bf530d..655ab75c 100644 --- a/web/api/utils.go +++ b/web/api/utils.go @@ -4,7 +4,7 @@ import "strings" func contains(s []string, e string) bool { for _, a := range s { - if strings.TrimSpace(strings.ToLower(a)) == strings.TrimSpace(strings.ToLower(e)) { + if strings.EqualFold(strings.TrimSpace(a), strings.TrimSpace(e)) { return true } } diff --git a/web/management/reset_password.go b/web/management/reset_password.go index 12646042..fb7e4b7b 100644 --- a/web/management/reset_password.go +++ b/web/management/reset_password.go @@ -4,6 +4,7 @@ import ( "net/http" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) @@ -28,9 +29,10 @@ func (ar *Router) getResetPasswordToken(w http.ResponseWriter, r *http.Request) user, err := ar.server.Storages().User.UserByEmail(d.Email) if err == model.ErrUserNotFound { // return ok, but there is no user - ar.logger.Printf("Trying to reset password for the user, which is not exists: %s. Sending back ok to user for security reason.", d.Email) - result := map[string]string{"result": "ok"} - ar.ServeJSON(w, locale, http.StatusOK, result) + ar.logger.Warn("Trying to reset password for the user, which is not exists. Sending back ok to user for security reason.", + logging.FieldEmail, d.Email) + + ar.ServeJSONOk(w) return } else if err != nil { ar.Error(w, locale, http.StatusInternalServerError, l.ErrorStorageFindUserEmailError, d.Email, err) diff --git a/web/management/router.go b/web/management/router.go index 81680719..8452a215 100644 --- a/web/management/router.go +++ b/web/management/router.go @@ -3,20 +3,20 @@ package management import ( "encoding/json" "fmt" - "log" + "log/slog" "net/http" - "os" "runtime" "github.com/go-chi/chi/v5" "github.com/go-playground/validator" l "github.com/madappgang/identifo/v2/localization" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" ) type RouterSettings struct { Server model.Server - Logger *log.Logger + Logger *slog.Logger LoggerSettings model.LoggerSettings Storage model.ManagementKeysStorage Locale string @@ -26,7 +26,7 @@ type RouterSettings struct { type Router struct { server model.Server ls *l.Printer // localized string - logger *log.Logger + logger *slog.Logger router *chi.Mux loggerSettings model.LoggerSettings stor model.ManagementKeysStorage @@ -51,7 +51,8 @@ func NewRouter(settings RouterSettings) (*Router, error) { // setup logger to stdout. if settings.Logger == nil { - ar.logger = log.New(os.Stdout, "MANAGEMENT_ROUTER: ", log.Ldate|log.Ltime|log.Lshortfile) + ar.logger = logging.NewDefaultLogger(). + With(logging.FieldComponent, "MANAGEMENT_ROUTER") } else { ar.logger = settings.Logger } @@ -77,8 +78,20 @@ func (ar *Router) ServeJSON(w http.ResponseWriter, locale string, status int, v w.Header().Set("Content-Type", "application/json") w.WriteHeader(status) + if _, err = w.Write(data); err != nil { - log.Printf("error writing http response: %s", err) + logging.DefaultLogger.Error("error writing http response", logging.FieldError, err) + } +} + +var jsonOkBody = []byte(`{"result": "ok"}`) + +func (ar *Router) ServeJSONOk(w http.ResponseWriter) { + w.Header().Set("Content-Type", "application/json") + + if _, err := w.Write(jsonOkBody); err != nil { + ar.logger.Error("error writing http response", + logging.FieldError, err) } } @@ -107,8 +120,11 @@ func (ar *Router) error(w http.ResponseWriter, callerDepth int, locale string, s } message := ar.ls.SL(locale, errID, details...) - // Log error. - ar.logger.Printf("api error: %v (status=%v). Details: %v. Where: %v:%d.", errID, status, message, file, no) + ar.logger.Error("api error", + logging.FieldErrorID, errID, + "status", status, + "details", message, + "where", fmt.Sprintf("%v:%d", file, no)) // Write generic error response. w.Header().Set("Content-Type", "application/json") @@ -127,7 +143,8 @@ func (ar *Router) error(w http.ResponseWriter, callerDepth int, locale string, s encodeErr := json.NewEncoder(w).Encode(resp) if encodeErr != nil { - ar.logger.Printf("error writing http response: %s", errID) + ar.logger.Error("error writing http response", + logging.FieldError, encodeErr) } } diff --git a/web/management/routes.go b/web/management/routes.go index ca803e71..1b7c6d91 100644 --- a/web/management/routes.go +++ b/web/management/routes.go @@ -8,9 +8,6 @@ import ( "github.com/go-chi/chi/v5/middleware" ) -func logger(name string) { -} - // setup all routes func (ar *Router) initRoutes() { // A good base middleware stack diff --git a/web/management/test.go b/web/management/test.go index c0f87bb2..bbeaee90 100644 --- a/web/management/test.go +++ b/web/management/test.go @@ -14,7 +14,8 @@ func (ar *Router) test(w http.ResponseWriter, r *http.Request) { locale := r.Header.Get("Accept-Language") - ar.logger.Println("trace pong handler") + ar.logger.Debug("trace pong handler") + pong := pongResponse{ Message: "Pong!", Date: time.Now(), diff --git a/web/middleware/middleware_app.go b/web/middleware/middleware_app.go index 647dec62..487660cd 100644 --- a/web/middleware/middleware_app.go +++ b/web/middleware/middleware_app.go @@ -2,11 +2,11 @@ package middleware import ( "context" - "log" + "log/slog" "net/http" - "os" "strings" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/urfave/negroni" ) @@ -17,12 +17,11 @@ const ( ) // AppID gets app id from the request body. -func AppID(errorPath string, appStorage model.AppStorage, logger *log.Logger) negroni.HandlerFunc { - // Setup logger to stdout. - if logger == nil { - logger = log.New(os.Stdout, "APP_ID_MIDDLEWARE: ", log.Ldate|log.Ltime|log.Lshortfile) - } - +func AppID( + logger *slog.Logger, + errorPath string, + appStorage model.AppStorage, +) negroni.HandlerFunc { return func(w http.ResponseWriter, r *http.Request, next http.HandlerFunc) { if strings.HasSuffix(errorPath, r.URL.Path) { next.ServeHTTP(w, r) @@ -43,7 +42,8 @@ func AppID(errorPath string, appStorage model.AppStorage, logger *log.Logger) ne app, err := appStorage.ActiveAppByID(appID) if err != nil { - logger.Printf("Error: getting app by id. %s", err) + logger.Error("Error: getting app by id", + logging.FieldError, err) http.Redirect(w, r, errorPath, http.StatusFound) return } diff --git a/web/middleware/negroni_logger.go b/web/middleware/negroni_logger.go deleted file mode 100644 index 3479ee10..00000000 --- a/web/middleware/negroni_logger.go +++ /dev/null @@ -1,16 +0,0 @@ -package middleware - -import ( - "fmt" - "log" - "os" - - "github.com/urfave/negroni" -) - -func NewNegroniLogger(name string) *negroni.Logger { - logger := negroni.NewLogger() - logger.ALogger = log.New(os.Stdout, fmt.Sprintf("[ %s ]: ", name), 0) - logger.SetFormat(negroni.LoggerDefaultFormat) - return logger -} diff --git a/web/router.go b/web/router.go index cce93cb1..b2119916 100644 --- a/web/router.go +++ b/web/router.go @@ -2,7 +2,7 @@ package web import ( "io/fs" - "log" + "log/slog" "net/http" "net/url" @@ -28,7 +28,7 @@ const ( // RouterSetting contains settings for root http router. type RouterSetting struct { Server model.Server - Logger *log.Logger + Logger *slog.Logger ServeAdminPanel bool Host *url.URL LoggerSettings model.LoggerSettings diff --git a/web/spa/router.go b/web/spa/router.go index c88f5513..ceb9f4c4 100644 --- a/web/spa/router.go +++ b/web/spa/router.go @@ -1,25 +1,27 @@ package spa import ( - "fmt" - "log" + "log/slog" "net/http" - "os" + "github.com/madappgang/identifo/v2/logging" "github.com/madappgang/identifo/v2/model" "github.com/madappgang/identifo/v2/web/middleware" "github.com/urfave/negroni" ) -func NewRouter(setting SPASettings, middlewares []negroni.Handler, logger *log.Logger) (model.Router, error) { +func NewRouter(setting SPASettings, middlewares []negroni.Handler, logger *slog.Logger) (model.Router, error) { ar := Router{ - Middleware: negroni.New(middleware.NewNegroniLogger(setting.Name), negroni.NewRecovery()).With(middlewares...), - FS: setting.FileSystem, + Middleware: negroni.New( + middleware.NewNegroniLogger(setting.Name), + negroni.NewRecovery()).With(middlewares...), + FS: setting.FileSystem, } // Setup logger to stdout. if logger == nil { - ar.Logger = log.New(os.Stdout, fmt.Sprintf("[ %s ]: ", setting.Name), log.Ldate|log.Ltime|log.Lshortfile) + ar.Logger = logging.NewDefaultLogger().With( + logging.FieldComponent, setting.Name) } ar.Middleware.UseHandler(NewSPAHandlerFunc(setting)) @@ -28,7 +30,7 @@ func NewRouter(setting SPASettings, middlewares []negroni.Handler, logger *log.L // login app router type Router struct { - Logger *log.Logger + Logger *slog.Logger Middleware *negroni.Negroni FS http.FileSystem }