From fb9652c6dd6961f10cb68cbefaaa582720b6c024 Mon Sep 17 00:00:00 2001 From: Carter Klein Date: Fri, 8 Jan 2021 18:41:51 -0500 Subject: [PATCH] Adding Uber zap leveled logging --- cmd/supertype/main.go | 25 ++++++- go.mod | 1 + go.sum | 3 + pkg/authenticating/errors.go | 10 +-- pkg/storage/dynamo/authenticatingImpl.go | 95 +++++++++++++++++------- pkg/storage/dynamo/consumingImpl.go | 16 +++- pkg/storage/dynamo/dashboardImpl.go | 30 ++++++-- pkg/storage/dynamo/producingImpl.go | 25 +++++-- 8 files changed, 151 insertions(+), 54 deletions(-) diff --git a/cmd/supertype/main.go b/cmd/supertype/main.go index 8e5d3b3..dff9217 100644 --- a/cmd/supertype/main.go +++ b/cmd/supertype/main.go @@ -1,22 +1,39 @@ package main import ( - "log" "net/http" - "github.com/fatih/color" "github.com/super-type/supertype/pkg/authenticating" "github.com/super-type/supertype/pkg/consuming" "github.com/super-type/supertype/pkg/dashboard" "github.com/super-type/supertype/pkg/http/rest" "github.com/super-type/supertype/pkg/producing" "github.com/super-type/supertype/pkg/storage/dynamo" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) +// Set up logging using Uber's Zap logger +func initLogger() *zap.Logger { + config := zap.NewDevelopmentConfig() + config.EncoderConfig.EncodeLevel = zapcore.CapitalColorLevelEncoder + config.EncoderConfig.TimeKey = "timestamp" + config.EncoderConfig.EncodeTime = zapcore.ISO8601TimeEncoder + logger, _ := config.Build() + return logger +} + func main() { // Initialize storage persistentStorage := new(dynamo.Storage) + // Initialize logger + loggerManager := initLogger() + zap.ReplaceGlobals(loggerManager) + defer loggerManager.Sync() // flushes buffer, if any + logger := loggerManager.Sugar() + // Initialize services authenticator := authenticating.NewService(persistentStorage) dashboard := dashboard.NewService(persistentStorage) @@ -25,6 +42,6 @@ func main() { // Initialize routers and startup server httpRouter := rest.Router(authenticator, producing, consuming, dashboard) - color.Cyan("Starting HTTP server on port 5000...") - log.Fatal(http.ListenAndServe(":5000", httpRouter)) + logger.Info("Starting HTTP server on port 5000...") + logger.Fatal(http.ListenAndServe(":5000", httpRouter)) } diff --git a/go.mod b/go.mod index f02a4d5..da2765a 100644 --- a/go.mod +++ b/go.mod @@ -14,5 +14,6 @@ require ( github.com/joho/godotenv v1.3.0 github.com/spf13/viper v1.7.1 github.com/stretchr/testify v1.6.1 + go.uber.org/zap v1.10.0 golang.org/x/crypto v0.0.0-20200709230013-948cd5f35899 ) diff --git a/go.sum b/go.sum index 64857f7..3f9ace0 100644 --- a/go.sum +++ b/go.sum @@ -229,8 +229,11 @@ go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= go.opencensus.io v0.22.0/go.mod h1:+kGneAE2xo2IficOXnaByMWTGM9T73dGwxeWcUqIpI8= go.opentelemetry.io/otel v0.11.0 h1:IN2tzQa9Gc4ZVKnTaMbPVcHjvzOdg5n9QfnmlqiET7E= go.opentelemetry.io/otel v0.11.0/go.mod h1:G8UCk+KooF2HLkgo8RHX9epABH/aRGYET7gQOqBVdB0= +go.uber.org/atomic v1.4.0 h1:cxzIVoETapQEqDhQu3QfnvXAV4AlzcvUCxkVUFw3+EU= go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= +go.uber.org/multierr v1.1.0 h1:HoEmRHQPVSqub6w2z2d2EOVs2fjyFRGyofhKuyDq0QI= go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0= +go.uber.org/zap v1.10.0 h1:ORx85nbTijNz8ljznvCMR1ZBIPKFn3jQrag10X2AsuM= go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20181029021203-45a5f77698d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= diff --git a/pkg/authenticating/errors.go b/pkg/authenticating/errors.go index 777e0fd..da54a22 100644 --- a/pkg/authenticating/errors.go +++ b/pkg/authenticating/errors.go @@ -5,8 +5,8 @@ import "errors" // ErrVendorNotFound is used when a vendor is not found in the database var ErrVendorNotFound = errors.New("Vendor not found") -// ErrVendorAlreadyExists is used when attempting to create an already-used username -var ErrVendorAlreadyExists = errors.New("Vendor already exists") +// ErrAlreadyExists is used when attempting to create an already-used username +var ErrAlreadyExists = errors.New("Vendor already exists") // ErrUserNotFound is used when a user is not found in the database var ErrUserNotFound = errors.New("User not found") @@ -30,10 +30,10 @@ var ErrGeneratingCipherBlock = errors.New("Error generating cipher block") var ErrGeneratingIV = errors.New("Error generating iv") // ErrInvalidEmailLength is used when an invalid email address length is used to create an account -var ErrInvalidEmailLength = errors.New("Invalid email address length. Account creation failed.") +var ErrInvalidEmailLength = errors.New("Invalid email address length. Account creation failed") // ErrInvalidEmailMatching is used when eamil regex matching fails -var ErrInvalidEmailMatching = errors.New("Invalid email - bad matching. Account creation failed.") +var ErrInvalidEmailMatching = errors.New("Invalid email - bad matching. Account creation failed") // ErrInvalidEmail is used when an invalid email address is used to create an account -var ErrInvalidEmail = errors.New("Invalid email address used. Account creation failed.") +var ErrInvalidEmail = errors.New("Invalid email address used. Account creation failed") diff --git a/pkg/storage/dynamo/authenticatingImpl.go b/pkg/storage/dynamo/authenticatingImpl.go index 443c881..9b37a4e 100644 --- a/pkg/storage/dynamo/authenticatingImpl.go +++ b/pkg/storage/dynamo/authenticatingImpl.go @@ -16,17 +16,18 @@ import ( "strings" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" - "github.com/fatih/color" "github.com/super-type/supertype/internal/keys" "github.com/super-type/supertype/internal/utils" "github.com/super-type/supertype/pkg/authenticating" "github.com/super-type/supertype/pkg/storage" + "go.uber.org/zap" ) var emailRegex = regexp.MustCompile("^[a-zA-Z0-9.!#$%&'*+\\/=?^_`{|}~-]+@[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?(?:\\.[a-zA-Z0-9](?:[a-zA-Z0-9-]{0,61}[a-zA-Z0-9])?)*$") // CreateVendor creates a new vendor and adds it to DynamoDB func (d *Storage) CreateVendor(v authenticating.Vendor) (*[2]string, error) { + zap.S().Info("Creating new vendor...") // Initialize AWS session svc := utils.SetupAWSSession() @@ -35,45 +36,56 @@ func (d *Storage) CreateVendor(v authenticating.Vendor) (*[2]string, error) { // Get username from DynamoDB result, err := GetItemDynamoDB(svc, "vendor", "username", v.Username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", v.Username, err) return nil, err } - user := Vendor{} - err = dynamodbattribute.UnmarshalMap(result.Item, &user) + vendor := Vendor{} + err = dynamodbattribute.UnmarshalMap(result.Item, &vendor) if err != nil { + zap.S().Errorf("Error unmarshaling vendor: %v", err) return nil, storage.ErrUnmarshaling } // Get email from DynamoDB email, err := ScanDynamoDB("vendor", "email", v.Email) if err != nil { + zap.S().Errorf("Error getting email %s from DynamoDB: %v", v.Email, err) return nil, err } // Check username, email doesn't exist - if user.Username != "" || len(email.Items) != 0 { - color.Red("Username or email already exists") - return nil, authenticating.ErrVendorAlreadyExists + if vendor.Username != "" { + zap.S().Errorf("Username %s already exists", vendor.Username) + return nil, authenticating.ErrAlreadyExists + } + + if len(email.Items) != 0 { + zap.S().Errorf("Email %s already exists", vendor.Username) + return nil, authenticating.ErrAlreadyExists } // Check email is a valid email address // TODO in a later refactor, this should be taken out of this function and put inside another... this is business logic, not database logic i.e. not depending on DynamoDB if len(v.Email) < 3 && len(v.Email) > 254 { + zap.S().Errorf("Email %s invalid length %v", v.Email, len(v.Email)) return nil, authenticating.ErrInvalidEmailLength } if !emailRegex.MatchString(v.Email) { + zap.S().Errorf("Email %s does not match regex", v.Email) return nil, authenticating.ErrInvalidEmailMatching } parts := strings.Split(v.Email, "@") mx, err := net.LookupMX(parts[1]) if err != nil || len(mx) == 0 { + zap.S().Errorf("Error looking up mx: %v", err) return nil, authenticating.ErrInvalidEmail } // Generate key pair for new vendor skVendor, pkVendor, err := keys.GenerateKeys() if err != nil { - color.Red("Failed to generate keys") + zap.S().Errorf("Failed to generate keys: %v", err) return nil, keys.ErrFailedToGenerateKeys } @@ -85,11 +97,13 @@ func (d *Storage) CreateVendor(v authenticating.Vendor) (*[2]string, error) { // Generate Supertype ID supertypeID, err := utils.GenerateSupertypeID(v.Password) if err != nil { + zap.S().Errorf("Error generating SupertypeID: %v", err) return nil, err } // Cursory check for valid email address if !utils.ValidateEmail(v.Email) { + zap.S().Errorf("Email %s invalid", v.Email) return nil, storage.ErrInvalidEmail } @@ -108,39 +122,45 @@ func (d *Storage) CreateVendor(v authenticating.Vendor) (*[2]string, error) { err = PutItemInDynamoDB(createVendor, "vendor", svc) if err != nil { + zap.S().Errorf("Error putting vendor %s in DynamoDB: %v", fmt.Sprint(createVendor), err) return nil, err } keyPair := [2]string{*pkVendor, *skVendor} + zap.S().Info("Successfully created new vendor!") return &keyPair, nil } // CreateUser creates a new user and adds it to DynamoDB func (d *Storage) CreateUser(u authenticating.UserPassword) (*string, error) { + zap.S().Info("Creating new user...") // Initialize AWS session svc := utils.SetupAWSSession() // Get username from DynamoDB result, err := GetItemDynamoDB(svc, "user", "username", u.Username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", u.Username, err) return nil, err } user := User{} err = dynamodbattribute.UnmarshalMap(result.Item, &user) if err != nil { + zap.S().Errorf("Error unmarshaling user: %v", err) return nil, storage.ErrUnmarshaling } // Check username doesn't exist if user.Username != "" { - color.Red("User already exists") + zap.S().Errorf("Error getting username %s from DynamoDB", user.Username) return nil, authenticating.ErrUserAlreadyExists } // Generate Supertype ID supertypeID, err := utils.GenerateSupertypeID(u.Password) if err != nil { + zap.S().Errorf("Error generating SupertypeID: %v", err) return nil, err } @@ -153,34 +173,38 @@ func (d *Storage) CreateUser(u authenticating.UserPassword) (*string, error) { // Upload new user to DynamoDB err = PutItemInDynamoDB(createUser, "user", svc) if err != nil { + zap.S().Errorf("Error putting vendor %s in DynamoDB: %v", fmt.Sprint(createUser), err) return nil, err } success := "success" + zap.S().Info("Successfully created new user!") return &success, nil } // LoginVendor logs in the given vendor to the repository func (d *Storage) LoginVendor(v authenticating.Vendor) (*authenticating.AuthenticatedVendor, error) { + zap.S().Info("Logging vendor in...") // Initialize AWS Session svc := utils.SetupAWSSession() // Get username from DynamoDB result, err := GetItemDynamoDB(svc, "vendor", "username", v.Username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", v.Username, err) return nil, err } vendor := authenticating.AuthenticatedVendor{} err = dynamodbattribute.UnmarshalMap(result.Item, &vendor) if err != nil { - color.Red("Error unmarshaling data") + zap.S().Errorf("Error unmarshaling user: %v", err) return nil, storage.ErrUnmarshaling } // Check vendor exists and get object if vendor.Username == "" { - color.Red("Vendor not found") + zap.S().Errorf("Error getting username %s from DynamoDB", vendor.Username) return nil, authenticating.ErrVendorNotFound } @@ -190,26 +214,26 @@ func (d *Storage) LoginVendor(v authenticating.Vendor) (*authenticating.Authenti "supertypeID": vendor.SupertypeID, }) if err != nil { - color.Red("Error encoding data") + zap.S().Errorf("Error encoding request: %v", err) return nil, storage.ErrEncoding } resp, err := http.Post("https://z1lwetrbfe.execute-api.us-east-1.amazonaws.com/default/login-vendor", "application/json", bytes.NewBuffer(requestBody)) if err != nil { - color.Red("Error requesting Supertype API") + zap.S().Errorf("Error requesting Supertype API: %v", err) return nil, authenticating.ErrRequestingAPI } defer resp.Body.Close() if resp.StatusCode != 200 { - color.Red("API request gave bad response status") + zap.S().Errorf("API request gave bad response status %v", resp.StatusCode) return nil, authenticating.ErrRequestingAPI } jwt, err := utils.GenerateJWT(vendor.Username) if err != nil { - color.Red("Could not generate JWT") + zap.S().Errorf("Could not generate JWT: %v", err) return nil, authenticating.ErrRequestingAPI } vendor.JWT = *jwt @@ -219,24 +243,26 @@ func (d *Storage) LoginVendor(v authenticating.Vendor) (*authenticating.Authenti // LoginUser logs in the given user to the repository func (d *Storage) LoginUser(u authenticating.UserPassword) (*authenticating.User, error) { + zap.S().Info("Creating user in...") // Initialize AWS Session svc := utils.SetupAWSSession() // Get username from DynamoDB result, err := GetItemDynamoDB(svc, "user", "username", u.Username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", u.Username, err) return nil, err } user := authenticating.User{} err = dynamodbattribute.UnmarshalMap(result.Item, &user) if err != nil { - color.Red("Error unmarshaling data") + zap.S().Errorf("Error unmarshaling user: %v", err) return nil, storage.ErrUnmarshaling } // Check user exists and get object if user.Username == "" { - color.Red("User not found") + zap.S().Errorf("Error getting username %s from DynamoDB", user.Username) return nil, authenticating.ErrUserNotFound } @@ -246,20 +272,20 @@ func (d *Storage) LoginUser(u authenticating.UserPassword) (*authenticating.User "supertypeID": user.SupertypeID, }) if err != nil { - color.Red("Error encoding data") + zap.S().Errorf("Error encoding request %s : %v", fmt.Sprint(requestBody), err) return nil, storage.ErrEncoding } resp, err := http.Post("https://z1lwetrbfe.execute-api.us-east-1.amazonaws.com/default/login-vendor", "application/json", bytes.NewBuffer(requestBody)) if err != nil { - color.Red("Error requesting Supertype API") + zap.S().Errorf("Error requesting Supertype API: %v", err) return nil, authenticating.ErrRequestingAPI } defer resp.Body.Close() if resp.StatusCode != 200 { - color.Red("API request gave bad response status") + zap.S().Errorf("API request gave bad response status %v", resp.StatusCode) return nil, authenticating.ErrRequestingAPI } @@ -270,10 +296,12 @@ func (d *Storage) LoginUser(u authenticating.UserPassword) (*authenticating.User // Encrypt block, err := aes.NewCipher(generationKey[0:32]) if err != nil { + zap.S().Errorf("Error generating new cipher block: %v", err) return nil, authenticating.ErrGeneratingCipherBlock } iv := make([]byte, aes.BlockSize) if _, err := rand.Read(iv); err != nil { + zap.S().Errorf("Error generating initialization vector: %v", err) return nil, authenticating.ErrGeneratingIV } cfb := cipher.NewCFBEncrypter(block, iv) @@ -283,29 +311,32 @@ func (d *Storage) LoginUser(u authenticating.UserPassword) (*authenticating.User // Set userKey value to return on login user.UserKey = base64.StdEncoding.EncodeToString(ciphertext) + zap.S().Info("Successfully logged in user!") return &user, nil } // AuthorizedLoginUser logs in the given user to the repository func (d *Storage) AuthorizedLoginUser(u authenticating.UserPassword, apiKey string) (*authenticating.User, error) { + zap.S().Info("Creating new user...") // Initialize AWS Session svc := utils.SetupAWSSession() // Get username from DynamoDB result, err := GetItemDynamoDB(svc, "user", "username", u.Username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", u.Username, err) return nil, err } user := authenticating.User{} err = dynamodbattribute.UnmarshalMap(result.Item, &user) if err != nil { - color.Red("Error unmarshaling data") + zap.S().Errorf("Error unmarshaling user: %v", err) return nil, storage.ErrUnmarshaling } // Check user exists and get object if user.Username == "" { - color.Red("User not found") + zap.S().Errorf("Error getting username %s from DynamoDB", user.Username) return nil, authenticating.ErrUserNotFound } @@ -315,20 +346,20 @@ func (d *Storage) AuthorizedLoginUser(u authenticating.UserPassword, apiKey stri "supertypeID": user.SupertypeID, }) if err != nil { - color.Red("Error encoding data") + zap.S().Errorf("Error encoding request: %v", err) return nil, storage.ErrEncoding } resp, err := http.Post("https://z1lwetrbfe.execute-api.us-east-1.amazonaws.com/default/login-vendor", "application/json", bytes.NewBuffer(requestBody)) if err != nil { - color.Red("Error requesting Supertype API") + zap.S().Errorf("Error requesting Supertype API: %v", err) return nil, authenticating.ErrRequestingAPI } defer resp.Body.Close() if resp.StatusCode != 200 { - color.Red("API request gave bad response status") + zap.S().Errorf("API request gave bad response status %v", resp.StatusCode) return nil, authenticating.ErrRequestingAPI } @@ -339,10 +370,12 @@ func (d *Storage) AuthorizedLoginUser(u authenticating.UserPassword, apiKey stri // Encrypt block, err := aes.NewCipher(generationKey[0:32]) if err != nil { + zap.S().Errorf("Error generating new cipher block: %v", err) return nil, authenticating.ErrGeneratingCipherBlock } iv := make([]byte, aes.BlockSize) if _, err := rand.Read(iv); err != nil { + zap.S().Errorf("Error generating initialization vector: %v", err) return nil, authenticating.ErrGeneratingIV } cfb := cipher.NewCFBEncrypter(block, iv) @@ -354,16 +387,20 @@ func (d *Storage) AuthorizedLoginUser(u authenticating.UserPassword, apiKey stri apiKeyHash := utils.GetAPIKeyHash(apiKey) - // Get venor's public key given the vendor's API Key + // Get vendor's public key given the vendor's API Key pk, err := ScanDynamoDBWithKeyCondition("vendor", "pk", "apiKeyHash", apiKeyHash) - if err != nil || pk == nil { - fmt.Println(err) + if err != nil { + zap.S().Errorf("Error getting vendor's public key given API Key: %v", err) return nil, err } + if pk == nil { + zap.S().Errorf("Public Key is empty") + } + pkAlreadyExists, err := ScanDynamoDBWithKeyCondition("user", "pk", "pk", *pk) if err != nil { - fmt.Println(err) + zap.S().Errorf("Public key already exists: %v", err) return nil, err } @@ -377,9 +414,11 @@ func (d *Storage) AuthorizedLoginUser(u authenticating.UserPassword, apiKey stri // Upload updated user to DynamoDB err = PutItemInDynamoDB(userWithVendors, "user", svc) if err != nil { + zap.S().Errorf("Error putting vendor %s in DynamoDB: %v", fmt.Sprint(userWithVendors), err) return nil, err } } + zap.S().Info("Successfully logged in authorized user!") return &user, nil } diff --git a/pkg/storage/dynamo/consumingImpl.go b/pkg/storage/dynamo/consumingImpl.go index ed93fb8..7d5ea01 100644 --- a/pkg/storage/dynamo/consumingImpl.go +++ b/pkg/storage/dynamo/consumingImpl.go @@ -1,23 +1,31 @@ package dynamo import ( - "github.com/fatih/color" + "fmt" + "github.com/super-type/supertype/internal/utils" "github.com/super-type/supertype/pkg/consuming" "github.com/super-type/supertype/pkg/storage" + "go.uber.org/zap" ) // Consume returns all observations at the requested attribute for the specified Supertype entity func (d *Storage) Consume(c consuming.ObservationRequest, apiKey string) (*consuming.ObservationResponse, error) { + zap.S().Info("Consuming attribute...") apiKeyHash := utils.GetAPIKeyHash(apiKey) databaseAPIKeyHash, err := ScanDynamoDBWithKeyCondition("vendor", "apiKeyHash", "apiKeyHash", apiKeyHash) - if err != nil || databaseAPIKeyHash == nil { + if err != nil { + zap.S().Errorf("Error getting API Key hash %s :%v", apiKeyHash, err) return nil, err } + if databaseAPIKeyHash == nil { + zap.S().Errorf("API Key hash %s is nil", apiKeyHash) + } + // Compare requesting API Key with our internal API Key. If they don't match, it's not coming from the vendor if *databaseAPIKeyHash != apiKeyHash { - color.Red("!!! Vendor secret key hashes do no match - potential malicious attempt !!!") + zap.S().Errorf("Stored API hash does not match given (%s) - potential malicious attempt!", apiKeyHash) return nil, storage.ErrAPIKeyDoesNotMatch } @@ -26,6 +34,7 @@ func (d *Storage) Consume(c consuming.ObservationRequest, apiKey string) (*consu val, err := GetItemDynamoDB(svc, c.Attribute, "supertypeID", c.SupertypeID) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", c.SupertypeID, err) return nil, err } @@ -36,5 +45,6 @@ func (d *Storage) Consume(c consuming.ObservationRequest, apiKey string) (*consu SupertypeID: *(val.Item["supertypeID"].S), } + zap.S().Infof("Successfully retrieved observation %s", fmt.Sprint(observation)) return &observation, nil } diff --git a/pkg/storage/dynamo/dashboardImpl.go b/pkg/storage/dynamo/dashboardImpl.go index 5deef98..2a38c60 100644 --- a/pkg/storage/dynamo/dashboardImpl.go +++ b/pkg/storage/dynamo/dashboardImpl.go @@ -7,10 +7,10 @@ import ( "strings" "github.com/aws/aws-sdk-go/service/dynamodb/dynamodbattribute" + "go.uber.org/zap" "github.com/aws/aws-sdk-go/aws/awserr" "github.com/aws/aws-sdk-go/service/dynamodb" - "github.com/fatih/color" "github.com/super-type/supertype/internal/utils" "github.com/super-type/supertype/pkg/authenticating" "github.com/super-type/supertype/pkg/dashboard" @@ -19,6 +19,7 @@ import ( // ListAttributes returns all observations in the Supertype ecosystem func (d *Storage) ListAttributes() ([]string, error) { + zap.S().Info("Listing attributes...") // Initialize AWS session svc := utils.SetupAWSSession() input := &dynamodb.ListTablesInput{} @@ -30,10 +31,10 @@ func (d *Storage) ListAttributes() ([]string, error) { result, err := svc.ListTables(input) if err != nil { if _, ok := err.(awserr.Error); ok { - color.Red("Dynamo internal server error") + zap.S().Error("Dynamo internal server error") return nil, dashboard.ErrDynamoInternalError } - color.Red("Dynamo error") + zap.S().Errorf("Dynamo error: %v", err) return nil, dashboard.ErrDynamoError } @@ -53,20 +54,23 @@ func (d *Storage) ListAttributes() ([]string, error) { } } + zap.S().Info("Successfully retrieved attributes") return response, nil } // RegisterWebhook creates a new webhook on a vendor's request func (d *Storage) RegisterWebhook(webhookRequest dashboard.WebhookRequest, apiKey string) error { + zap.S().Info("Registering webhook...") apiKeyHash := utils.GetAPIKeyHash(apiKey) databaseAPIKeyHash, err := ScanDynamoDBWithKeyCondition("vendor", "apiKeyHash", "apiKeyHash", apiKeyHash) if err != nil || databaseAPIKeyHash == nil { + zap.S().Errorf("Error getting vendor's public key given API Key: %v", err) return err } // Compare requesting API Key with our internal API Key. If they don't match, it's not coming from the vendor if *databaseAPIKeyHash != apiKeyHash { - color.Red("!!! Vendor secret key hashes do no match - potential malicious attempt !!!") + zap.S().Errorf("Stored API hash does not match given (%s) - potential malicious attempt!", apiKeyHash) return storage.ErrAPIKeyDoesNotMatch } @@ -89,11 +93,13 @@ func (d *Storage) RegisterWebhook(webhookRequest dashboard.WebhookRequest, apiKe // Get attribute from subscribers result, err := GetItemDynamoDB(svc, "subscribers", "attribute", destination[0]) if err != nil { + zap.S().Errorf("Failed to get subscribers to %v from DynamoDB: %v", destination[0], err) return err } var levels interface{} err = dynamodbattribute.UnmarshalMap(result.Item, &levels) if err != nil { + zap.S().Errorf("Error unmarshaling levels: %v", err) return err } @@ -102,35 +108,39 @@ func (d *Storage) RegisterWebhook(webhookRequest dashboard.WebhookRequest, apiKe var attribute dashboard.MasterBedroom err = dynamodbattribute.UnmarshalMap(result.Item, &attribute) if err != nil { + zap.S().Errorf("Error unmarshaling attribute: %v", err) return err } b, err := json.Marshal(attribute) if err != nil { + zap.S().Errorf("Error encoding request: %v", err) return err } err = utils.ValidateNewSubscriberURL(string(b), webhookRequest.Endpoint) if err != nil { + zap.S().Errorf("Error validating endpoint %v : %v", webhookRequest.Endpoint, err) return err } urls := GetSubscribersFromEndpoint(destination, levels) updatedAttribute, err := utils.AppendToSubscribers(string(b), urls, webhookRequest.Endpoint) if err != nil { + zap.S().Errorf("Error appending to endpoint: %v", err) return err } resp := dashboard.MasterBedroom{} err = json.Unmarshal([]byte(*updatedAttribute), &resp) if err != nil { - fmt.Println(err) + zap.S().Errorf("Error unmarshaling attribute %s : %v", *updatedAttribute, err) return err } err = PutItemInDynamoDB(resp, "subscribers", svc) if err != nil { - fmt.Println(err) + zap.S().Errorf("Error putting item %s in DynamoDB: %v", fmt.Sprint(resp), err) return err } // This could get ugly, fast... we should try to think of a way to do this more programmatically @@ -142,22 +152,25 @@ func (d *Storage) RegisterWebhook(webhookRequest dashboard.WebhookRequest, apiKe case "garage": case "bathroom": default: + zap.S().Errorf("Invalid attribute %s : %v", destination[0]) return errors.New("Invalid attribute") } username, err := ScanDynamoDBWithKeyCondition("vendor", "username", "apiKeyHash", apiKeyHash) if err != nil { + zap.S().Errorf("Username already exists: %v", err) return err } result, err = GetItemDynamoDB(svc, "vendor", "username", *username) if err != nil { + zap.S().Errorf("Failed to get vendor from DynamoDB: %v", err) return err } vendor := authenticating.CreateVendor{} err = dynamodbattribute.UnmarshalMap(result.Item, &vendor) if err != nil { - color.Red("Error unmarshaling data") + zap.S().Errorf("Error unmarshaling vendor: %v", err) return storage.ErrUnmarshaling } @@ -180,9 +193,10 @@ func (d *Storage) RegisterWebhook(webhookRequest dashboard.WebhookRequest, apiKe // The URL can't exist in one place but not the other... maybe this is bad practice without a single source of truth? err = PutItemInDynamoDB(updatedVendor, "vendor", svc) if err != nil { - fmt.Println(err) + zap.S().Errorf("Error putting vendor %s in DynamoDB: %v", fmt.Sprint(updatedVendor), err) return err } + zap.S().Info("Successfully registered webhook!") return nil } diff --git a/pkg/storage/dynamo/producingImpl.go b/pkg/storage/dynamo/producingImpl.go index f3ecf1b..66e37c1 100644 --- a/pkg/storage/dynamo/producingImpl.go +++ b/pkg/storage/dynamo/producingImpl.go @@ -15,25 +15,28 @@ import ( "github.com/super-type/supertype/pkg/authenticating" "github.com/super-type/supertype/pkg/producing" "github.com/super-type/supertype/pkg/storage" + "go.uber.org/zap" ) // Produce produces encyrpted data to Supertype func (d *Storage) Produce(o producing.ObservationRequest, apiKey string) error { + zap.S().Info("Producing new observation...") apiKeyHash := utils.GetAPIKeyHash(apiKey) databaseAPIKeyHash, err := ScanDynamoDBWithKeyCondition("vendor", "apiKeyHash", "apiKeyHash", apiKeyHash) if err != nil || databaseAPIKeyHash == nil { + zap.S().Errorf("Error getting API Key hash %s : %v", apiKeyHash, err) return err } pk, err := ScanDynamoDBWithKeyCondition("vendor", "pk", "apiKeyHash", apiKeyHash) if err != nil || pk == nil { - fmt.Println(err) + zap.S().Errorf("Error getting vendor's public key given API Key: %v", err) return err } // Compare requesting API Key with our internal API Key. If they don't match, it's not coming from the vendor if *databaseAPIKeyHash != apiKeyHash { - color.Red("!!! Vendor secret key hashes do no match - potential malicious attempt !!!") + zap.S().Errorf("Stored API hash does not match given (%s) - potential malicious attempt!", apiKeyHash) return storage.ErrAPIKeyDoesNotMatch } @@ -54,22 +57,25 @@ func (d *Storage) Produce(o producing.ObservationRequest, apiKey string) error { // Upload new observation to DynamoDB err = PutItemInDynamoDB(d.Observation, o.Attribute, svc) if err != nil { + zap.S().Errorf("Error putting vendor %s in DynamoDB: %v", fmt.Sprint(d.Observation), err) return err } // 1. Associate supertypeID with user, and get all vendors associated with that user username, err := ScanDynamoDBWithKeyCondition("user", "username", "supertypeID", o.SupertypeID) if err != nil { + zap.S().Errorf("Username already exists: %v", err) return err } result, err := GetItemDynamoDB(svc, "user", "username", *username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", *username, err) return err } user := authenticating.UserWithVendors{} err = dynamodbattribute.UnmarshalMap(result.Item, &user) if err != nil { - color.Red("Error unmarshaling data") + zap.S().Errorf("Error unmarshaling user: %v", err) return storage.ErrUnmarshaling } var webhooks []string @@ -78,10 +84,12 @@ func (d *Storage) Produce(o producing.ObservationRequest, apiKey string) error { for _, vendor := range user.Vendors { username, err := ScanDynamoDBWithKeyCondition("vendor", "username", "pk", vendor) if err != nil { + zap.S().Errorf("Username already exists: %v", err) return err } result, err := GetItemDynamoDB(svc, "vendor", "username", *username) if err != nil { + zap.S().Errorf("Failed to get username %s from DynamoDB: %v", *username, err) return err } for _, url := range result.Item["webhooks"].L { @@ -96,15 +104,18 @@ func (d *Storage) Produce(o producing.ObservationRequest, apiKey string) error { // Get attribute from subscribers result, err = GetItemDynamoDB(svc, "subscribers", "attribute", destination[0]) if err != nil { + zap.S().Errorf("Failed to get subscribers %v from DynamoDB: %v", destination[0], err) return err } var levels interface{} err = dynamodbattribute.UnmarshalMap(result.Item, &levels) if err != nil { + zap.S().Errorf("Error unmarshaling item %v", err) return err } if levels == nil { + zap.S().Errorf("Attribute %v not found: %v", destination[0]) return errors.New("Couldn't find attribute") } @@ -125,14 +136,14 @@ func (d *Storage) Produce(o producing.ObservationRequest, apiKey string) error { "supertypeID": d.Observation.SupertypeID, }) if err != nil { - color.Red("Error marshaling data") + zap.S().Errorf("Error encoding request %s: %v", fmt.Sprint(requestBody), err) return err } client := &http.Client{} req, err := http.NewRequest("POST", webhookURL, bytes.NewReader(requestBody)) if err != nil { - fmt.Println(err) + zap.S().Errorf("Error creating HTTP request: %v", err) return err } req.Header.Add("Content-Type", "application/json") @@ -140,16 +151,18 @@ func (d *Storage) Produce(o producing.ObservationRequest, apiKey string) error { resp, err := client.Do(req) if err != nil { - color.Red("Error sending Webhook request") + zap.S().Errorf("Error sending HTTP request: %v", err) return err } // TODO make this more granular if resp.StatusCode >= 400 && resp.StatusCode < 600 { + zap.S().Errorf("Invalid Webhook response: %v", resp.StatusCode) return errors.New("Error sending Webhook request") } } } + zap.S().Info("Successfully produced new observation!") return nil }