package logs import ( "bytes" "encoding/json" "fmt" "github.com/MindscapeHQ/raygun4go" log "github.com/sirupsen/logrus" "gitlab.bob.co.za/bob-public-utils/bobgroup-go-utils/date_utils" "gitlab.bob.co.za/bob-public-utils/bobgroup-go-utils/errors" "gitlab.bob.co.za/bob-public-utils/bobgroup-go-utils/string_utils" "gitlab.bob.co.za/bob-public-utils/bobgroup-go-utils/utils" "io" "net/http" "net/url" "os" "reflect" "regexp" "runtime" "strings" "github.com/aws/aws-lambda-go/events" ) const ( FatalLevel = log.FatalLevel ErrorLevel = log.ErrorLevel WarnLevel = log.WarnLevel InfoLevel = log.InfoLevel DebugLevel = log.DebugLevel ) type LogEntryWithLevel struct { // LogBuffer *bytes.Buffer LogEntry *log.Entry Message interface{} LogLevel log.Level } var logger *log.Entry var cachedLogEntries []LogEntryWithLevel var apiRequest *events.APIGatewayProxyRequest var currentRequestID *string var isDebug = false var storeLogsUntilTriggered = false var disableLogging = false var build string var raygunClient *raygun4go.Client // Password filtering var passwordRegex = regexp.MustCompile(`(?i:\\?"password\\?"\s*:\s*\\?"(.*)\\?").*`) var byteArrayRegex = regexp.MustCompile(`(?i:\\?"(?i:[\w]*)(?i:byte|data)(?i:[\w]*)\\?"\s*:\s*\[([\d\s,]+)*\])`) func SanitiseLogs(logString string) string { var isValidJsonString bool isValidJsonString, logString = string_utils.PrettyJSON(logString) if !isValidJsonString { return logString } logString = MaskByteArraysInJsonString(logString) logString = MaskPasswordsInJsonString(logString) return logString } // MaskPasswordsInJsonString takes a string and sanitises all the instances of fields named password. // E.g. "{"password": "xyz123"}" will become "{"password": "***"}" func MaskPasswordsInJsonString(jsonString string) string { return string_utils.ReplaceAllRegexStringSubmatch(passwordRegex, jsonString, "***") } // MaskByteArraysInJsonString takes a string and truncates all the instances of number array fields have the word // "byte" in the name. E.g. {"file_bytes": [123,68,103]} will become "{"file_bytes": [...]}" func MaskByteArraysInJsonString(jsonString string) string { return string_utils.ReplaceAllRegexStringSubmatch(byteArrayRegex, jsonString, "...") } func SanitiseFields(fields map[string]interface{}) map[string]interface{} { sanitisedFields := make(map[string]interface{}) // Check if each field is a string or string pointer, and sanitize them if they are for key, field := range fields { value := reflect.ValueOf(field) if value.Kind() == reflect.Ptr && value.IsValid() { pointerValue := value.Elem() if pointerValue.Kind() == reflect.String { sanitisedString := SanitiseLogs(pointerValue.String()) sanitisedFields[key] = &sanitisedString } else { // Don't sanitise fields that are not strings sanitisedFields[key] = field } } else if value.Kind() == reflect.String { sanitisedFields[key] = SanitiseLogs(value.String()) } else { // Don't sanitise fields that are not strings sanitisedFields[key] = field } } return sanitisedFields } func InitLogs(requestID *string, isDebugBuild bool, buildVersion string, request *events.APIGatewayProxyRequest, client *raygun4go.Client) { currentRequestID = requestID apiRequest = request isDebug = isDebugBuild build = buildVersion raygunClient = client disableLogging = false storeLogsUntilTriggered = false cachedLogEntries = []LogEntryWithLevel{} if isDebugBuild { log.SetReportCaller(true) log.SetFormatter(&log.TextFormatter{ ForceColors: true, PadLevelText: true, DisableTimestamp: true, CallerPrettyfier: func(f *runtime.Frame) (string, string) { // Exclude the caller, will rather be added as a field return "", "" }, }) } else { log.SetReportCaller(true) log.SetFormatter(&CustomLogFormatter{}) } log.SetLevel(LogLevel()) val, exists := os.LookupEnv("DEBUGGING") if exists && val == "true" { log.SetLevel(log.TraceLevel) log.SetReportCaller(true) } logger = log.WithFields(log.Fields{ "environment": getEnvironment(), }) if requestID != nil { logger = log.WithFields(log.Fields{ "request_id": *requestID, }) } } func SetLevel(logLevel log.Level) { log.SetLevel(logLevel) } func LogLevel() log.Level { logLevelString := os.Getenv("LOG_LEVEL") logLevel := log.InfoLevel if logLevelString != "" { logLevelString = strings.ToLower(logLevelString) switch logLevelString { case "error": logLevel = log.ErrorLevel case "warn": logLevel = log.WarnLevel case "info": logLevel = log.InfoLevel case "debug": logLevel = log.DebugLevel } log.SetLevel(logLevel) } return logLevel } func getEnvironment() string { environment := os.Getenv("ENVIRONMENT") if environment == "" { environment = "dev" os.Setenv("ENVIRONMENT", "dev") } return environment } func getLogger() *log.Entry { if logger == nil { logger = log.WithFields(log.Fields{ "environment": getEnvironment(), }) } return logger } func InfoWithFields(fields map[string]interface{}, message interface{}) { if disableLogging { return } if reflect.TypeOf(message).Kind() == reflect.String { message = SanitiseLogs(message.(string)) } sanitisedFields := SanitiseFields(fields) logEntry := getLogger().WithFields(sanitisedFields) if storeLogsUntilTriggered { storeLogEntry(logEntry, message, log.InfoLevel) } else { logEntry.Info(message) } } func Info(format string, a ...interface{}) { if disableLogging { return } message := SanitiseLogs(fmt.Sprintf(format, a...)) logEntry := getLogger() if storeLogsUntilTriggered { storeLogEntry(logEntry, message, log.InfoLevel) } else { logEntry.Info(message) } } func ErrorWithFields(fields map[string]interface{}, err error) { if disableLogging { return } sanitisedFields := SanitiseFields(fields) sendRaygunError(sanitisedFields, err) logEntry := getLogger().WithFields(sanitisedFields) if storeLogsUntilTriggered { storeLogEntry(logEntry, err, log.ErrorLevel) } else { logEntry.Error(err) } } func ErrorWithMsg(format string, err error, a ...interface{}) { if disableLogging { return } message := SanitiseLogs(fmt.Sprintf(format, a...)) if err == nil { err = errors.Error(message) } ErrorWithFields(map[string]interface{}{ "message": message, }, err) } func ErrorMsg(format string, a ...interface{}) { if disableLogging { return } message := SanitiseLogs(fmt.Sprintf(format, a...)) ErrorWithMsg(message, nil) } func Warn(format string, a ...interface{}) { if disableLogging { return } message := SanitiseLogs(fmt.Sprintf(format, a...)) logEntry := getLogger() if storeLogsUntilTriggered { storeLogEntry(logEntry, message, log.WarnLevel) } else { logEntry.Warn(message) } } func WarnWithFields(fields map[string]interface{}, err error) { if disableLogging { return } sanitisedFields := SanitiseFields(fields) logEntry := getLogger().WithFields(sanitisedFields) if storeLogsUntilTriggered { storeLogEntry(logEntry, err, log.WarnLevel) } else { logEntry.Warn(err) } } func SQLDebugInfo(sql string) { if disableLogging { return } logEntry := getLogger().WithFields(map[string]interface{}{ "sql": sql, }) if storeLogsUntilTriggered { storeLogEntry(logEntry, "SQL query", log.DebugLevel) } else { logEntry.Debug("SQL query") } } func LogShipmentID(id int64) { if disableLogging { return } InfoWithFields(map[string]interface{}{ "shipment_id": id, }, "Current-shipment-ID") } func LogRequestInfo(req events.APIGatewayProxyRequest, shouldExcludeBody bool, extraFields map[string]interface{}) { if disableLogging { return } fields := map[string]interface{}{ "path": req.Path, "method": req.HTTPMethod, } if !shouldExcludeBody { fields["body"] = req.Body } if req.QueryStringParameters != nil { fields["query"] = req.QueryStringParameters } if req.Headers["client-version"] != "" { fields["client_version"] = req.Headers["client-version"] } for k, v := range extraFields { if k != "" { fields[k] = v } } InfoWithFields(fields, "Req") } func LogResponseInfo(req events.APIGatewayProxyRequest, res events.APIGatewayProxyResponse, err error) { if disableLogging { return } fields := map[string]interface{}{ "status_code": res.StatusCode, "path": req.Path, "method": req.HTTPMethod, } if err != nil { fields["error"] = err } if req.HTTPMethod == http.MethodPost || req.HTTPMethod == http.MethodPatch || req.HTTPMethod == http.MethodPut { fields["body"] = res.Body } InfoWithFields(fields, "Res") } func LogFullResponseInfo(res events.APIGatewayProxyResponse, err error) { if disableLogging { return } fields := map[string]interface{}{ "status_code": res.StatusCode, } if err != nil { fields["error"] = err } fields["body"] = res.Body InfoWithFields(fields, "Res") } func LogApiAudit(fields log.Fields) { if disableLogging { return } logEntry := getLogger().WithFields(fields) if storeLogsUntilTriggered { storeLogEntry(logEntry, "api-audit-log", log.InfoLevel) } else { logEntry.Info("api-audit-log") } } func LogSQSEvent(event events.SQSEvent) { if disableLogging { return } sqsReducedEvents := []map[string]string{} for _, record := range event.Records { reducedEvent := map[string]string{ "message_id": record.MessageId, "body": record.Body, "sender": record.Attributes["SenderId"], } for key, attribute := range record.MessageAttributes { if key != "Name" { reducedEvent[key] = *attribute.StringValue } } sqsReducedEvents = append(sqsReducedEvents, reducedEvent) } InfoWithFields(map[string]interface{}{ "records": sqsReducedEvents, }, "") } func LogWebsocketEvent(req events.APIGatewayWebsocketProxyRequest, shouldExcludeBody bool) { if disableLogging { return } fields := map[string]interface{}{ "route": req.RequestContext.RouteKey, "connection_id": req.RequestContext.ConnectionID, } if !shouldExcludeBody { fields["body"] = req.Body } InfoWithFields(fields, "Req") } func SetOutput(out io.Writer) { log.SetOutput(out) } func SetOutputToFile(file *os.File) { log.SetOutput(file) } func StoreLogsUntilTriggered(storeLogs bool) { storeLogsUntilTriggered = storeLogs } func DisableLogging() { disableLogging = true } func ClearInfo() { logger = nil cachedLogEntries = []LogEntryWithLevel{} } func sendRaygunError(fields map[string]interface{}, errToSend error) { if isDebug || raygunClient == nil { // Don't log raygun errors on debug return } if customErr, ok := errToSend.(*errors.CustomError); ok && customErr.ShouldBypassRaygun() { return } env := getEnvironment() tags := []string{env} raygunClient.Version(build) tags = append(tags, build) if apiRequest != nil { methodAndPath := apiRequest.HTTPMethod + ": " + apiRequest.Path tags = append(tags, methodAndPath) fields["body"] = apiRequest.Body fields["query"] = apiRequest.QueryStringParameters fields["identity"] = apiRequest.RequestContext.Identity } raygunClient.Tags(tags) if currentRequestID != nil { fields["request_id"] = currentRequestID } fields["env"] = env sanitisedFields := SanitiseFields(fields) raygunClient.CustomData(sanitisedFields) raygunClient.Request(fakeHttpRequest()) if errToSend == nil { errToSend = errors.Error("") } err := raygunClient.SendError(errToSend) if err != nil { log.Println("Failed to send raygun error:", err.Error()) } } func fakeHttpRequest() *http.Request { if apiRequest == nil { return nil } // Mask authorization header for raygun logs headers := utils.DeepCopy(apiRequest.MultiValueHeaders).(map[string][]string) if len(headers["authorization"]) != 0 { headers["authorization"] = []string{"***"} } if len(headers["Authorization"]) != 0 { headers["Authorization"] = []string{"***"} } requestURL := url.URL{ Path: apiRequest.Path, Host: apiRequest.Headers["Host"], } request := http.Request{ Method: apiRequest.HTTPMethod, URL: &requestURL, Header: headers, } return &request } type CustomLogFormatter struct { } func (f *CustomLogFormatter) Format(entry *log.Entry) ([]byte, error) { data := map[string]any{} for k, v := range entry.Data { switch v := v.(type) { case error: // Otherwise errors are ignored by `encoding/json` // https://github.com/sirupsen/logrus/issues/137 data[k] = v.Error() default: data[k] = v } } if entry.Message != "" { data["msg"] = entry.Message } // Format body if value, ok := data["body"].(string); ok { cleanValue := strings.ReplaceAll(value, "\n", "") cleanValue = strings.ReplaceAll(cleanValue, "\"", "'") data["body"] = cleanValue } var b *bytes.Buffer if entry.Buffer != nil { b = entry.Buffer } else { b = &bytes.Buffer{} } encoder := json.NewEncoder(b) encoder.SetEscapeHTML(true) if err := encoder.Encode(data); err != nil { return nil, fmt.Errorf("failed to marshal fields to JSON, %w", err) } return b.Bytes(), nil } func storeLogEntry(logEntry *log.Entry, message interface{}, logLevel log.Level) { if logEntry != nil && logEntry.Logger != nil && logEntry.Logger.IsLevelEnabled(logLevel) { logWithTime := logEntry.WithField("log_time", date_utils.CurrentDate()) cachedLogEntries = append(cachedLogEntries, LogEntryWithLevel{ LogEntry: logWithTime, Message: message, LogLevel: logLevel, }) } } func LogAllStoredLogs() { log.SetOutput(os.Stderr) for _, cachedLogEntry := range cachedLogEntries { switch cachedLogEntry.LogLevel { case log.InfoLevel: cachedLogEntry.LogEntry.Info(cachedLogEntry.Message) case log.ErrorLevel: cachedLogEntry.LogEntry.Error(cachedLogEntry.Message) case log.WarnLevel: cachedLogEntry.LogEntry.Warn(cachedLogEntry.Message) case log.DebugLevel: cachedLogEntry.LogEntry.Debug(cachedLogEntry.Message) } } }