logs.go

package logs

import (
	"bytes"
	"encoding/json"
	"fmt"
	"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"
	"net/http"
	"net/url"
	"os"
	"reflect"
	"regexp"
	"runtime"
	"strings"

	"github.com/MindscapeHQ/raygun4go"

	"github.com/aws/aws-lambda-go/events"
	log "github.com/sirupsen/logrus"
)

var logger *log.Entry

var apiRequest *events.APIGatewayProxyRequest
var currentRequestID *string
var isDebug = false
var build string
var raygunClient *raygun4go.Client

// Password filtering
var passwordRegex = regexp.MustCompile(`(?i:\\?"password\\?"\s*:\s*\\?"(.*)\\?",).*`)

func SanitiseLogs(logString string) string {
	logString = MaskPasswordsInJsonString(logString)

	return logString
}

// MaskPasswordsInJsonString takes a string and, if it is a JSON string, sanitises all the password. In order for the
// regex to work correctly we need to prettify the JSON, so the function always returns a formatted JSON string.
func MaskPasswordsInJsonString(jsonString string) string {
	var isValidJsonString bool
	isValidJsonString, jsonString = string_utils.PrettyJSON(jsonString)
	if !isValidJsonString {
		return jsonString
	}

	if passwordRegex.MatchString(jsonString) {
		result := passwordRegex.FindAllStringSubmatch(jsonString, -1)
		for _, match := range result {
			if len(match) > 1 {
				jsonString = strings.ReplaceAll(jsonString, match[1], "***")
			}
		}
	}

	return 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 if value.Kind() == reflect.String {
			sanitisedFields[key] = SanitiseLogs(value.String())
		} else {
			// Don't sanitise fields that
			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

	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 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 reflect.TypeOf(message).Kind() == reflect.String {
		message = SanitiseLogs(message.(string))
	}
	sanitisedFields := SanitiseFields(fields)
	getLogger().WithFields(sanitisedFields).Info(message)
}

func Info(format string, a ...interface{}) {
	message := SanitiseLogs(fmt.Sprintf(format, a...))
	getLogger().Info(message)
}

func ErrorWithFields(fields map[string]interface{}, err error) {
	sanitisedFields := SanitiseFields(fields)
	sendRaygunError(sanitisedFields, err)
	getLogger().WithFields(sanitisedFields).Error(err)
}

func ErrorWithMsg(message string, err error) {
	if err == nil {
		err = errors.Error(message)
	}
	ErrorWithFields(map[string]interface{}{
		"message": message,
	}, err)
}

func ErrorMsg(message string) {
	ErrorWithMsg(message, nil)
}

func Warn(format string, a ...interface{}) {
	message := SanitiseLogs(fmt.Sprintf(format, a...))
	getLogger().Warn(message)
}

func WarnWithFields(fields map[string]interface{}, err error) {
	sanitisedFields := SanitiseFields(fields)
	getLogger().WithFields(sanitisedFields).Warn(err)
}

func SQLDebugInfo(sql string) {
	getLogger().WithFields(map[string]interface{}{
		"sql": sql,
	}).Debug("SQL query")
}

func LogShipmentID(id int64) {
	InfoWithFields(map[string]interface{}{
		"shipment_id": id,
	}, "Current-shipment-ID")
}

func LogRequestInfo(req events.APIGatewayProxyRequest, shouldExcludeBody bool, extraFields map[string]interface{}) {
	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) {
	fields := map[string]interface{}{
		"status_code": res.StatusCode,
	}

	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 LogApiAudit(fields log.Fields) {
	getLogger().WithFields(fields).Info("api-audit-log")
}

func LogSQSEvent(event events.SQSEvent) {
	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 SetOutputToFile(file *os.File) {
	log.SetOutput(file)
}

func ClearInfo() {
	logger = nil
}

func sendRaygunError(fields map[string]interface{}, errToSend error) {
	if isDebug || raygunClient == nil {
		// Don't log raygun errors on debug
		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
}