logger.go

package logger

import (
	"context"
	"fmt"
	"io"
	"log"
	"net"
	"net/url"
	"os"
	"os/signal"
	"strings"
	"sync"
	"syscall"
	"time"

	kv "github.com/Clever/kayvee-go/v7"
	"github.com/Clever/kayvee-go/v7/router"
	wcl "github.com/Clever/wag/logging/wagclientlogger"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/exporters/otlp/otlpmetric"
	"go.opentelemetry.io/otel/exporters/otlp/otlpmetric/otlpmetricgrpc"
	"go.opentelemetry.io/otel/metric/global"
	otlController "go.opentelemetry.io/otel/sdk/metric/controller/basic"
	otlProcessor "go.opentelemetry.io/otel/sdk/metric/processor/basic"
	"go.opentelemetry.io/otel/sdk/metric/selector/simple"
	"go.opentelemetry.io/otel/sdk/resource"
)

var globalOTLController *otlController.Controller

func getEnvMaybeWithPrefix(prefix string, key string) string {
	if val, ok := os.LookupEnv(prefix + key); ok {
		return val
	}
	return os.Getenv(key)
}

func init() {
	if otelCollectorURL := getEnvMaybeWithPrefix("_", "OTEL_COLLECTOR_URL"); otelCollectorURL != "" {
		up, err := url.Parse(otelCollectorURL)
		if err != nil {
			fmt.Fprintf(os.Stderr, "failed to parse otel collector url '%s': %v\n", otelCollectorURL, err)
		} else if up.Scheme != "tcp" {
			fmt.Fprintf(os.Stderr, "otel collector url '%s' is %s, not tcp\n", otelCollectorURL, up.Scheme)
		} else {
			if err := setupOtlMetrics(up.Host); err != nil {
				fmt.Fprintf(os.Stderr, "%v\n", err)
			}
		}
	}
}

/////////////////////
//
//  Helper definitions
//
/////////////////////

// Formatter is a function type that takes a map and returns a formatted string with the contents of the map
type Formatter func(data map[string]interface{}) string

// M is a convenience type for passing data into a log message.
type M map[string]interface{}

// LogLevel is an enum is used to denote level of logging
type LogLevel int

// Constants used to define different LogLevels supported
const (
	Trace LogLevel = iota
	Debug
	Info
	Warning
	Error
	Critical
)

var logLevelNames = map[LogLevel]string{
	Trace:    "trace",
	Debug:    "debug",
	Info:     "info",
	Warning:  "warning",
	Error:    "error",
	Critical: "critical",
}

func (l LogLevel) String() string {
	switch l {
	case Trace:
		fallthrough
	case Debug:
		fallthrough
	case Info:
		fallthrough
	case Warning:
		fallthrough
	case Error:
		fallthrough
	case Critical:
		return logLevelNames[l]
	}
	return ""
}

// metricsOutput is an enum is used to denote the output of metrics
type metricsOutput int

// Constants used to define different MetricsOutput supported
const (
	logMetrics metricsOutput = iota
	otlMetrics
)

// Timer is a helper structure used in logger.Timer method
type Timer struct {
	Logger    *Logger
	StartedAt time.Time
	Title     string
}

// Stop is a helper function used in logger.Timer method
func (t *Timer) Stop() {
	elapsedTimeSeconds := time.Now().Sub(t.StartedAt).Seconds()
	t.Logger.DebugD(t.Title+"-end", M{"elapsedTimeSeconds": elapsedTimeSeconds})
}

/////////////////////////////
//
//	Logger
//
/////////////////////////////

// Logger is the default implementation of KayveeLogger.
// It provides customization of globals, default log level, formatting, and output destination.
type Logger struct {
	globalsL      sync.RWMutex
	globals       map[string]interface{}
	logLvl        LogLevel
	fLogger       formatLogger
	logRouter     router.Router
	metricsOutput metricsOutput
}

var globalRouter router.Router

var reservedKeyNames = map[string]bool{
	"title":   true,
	"source":  true,
	"value":   true,
	"type":    true,
	"level":   true,
	"_kvmeta": true,
}

// SetGlobalRouting installs a new log router onto the KayveeLogger with the
// configuration specified in `filename`. For convenience, the KayveeLogger is expected
// to return itself as the first return value.
func SetGlobalRouting(filename string) error {
	var err error
	globalRouter, err = router.NewFromConfig(filename)
	return err
}

// SetGlobalRoutingFromBytes installs a new log router onto the KayveeLogger with the
// configuration specified in . For convenience, the KayveeLogger is expected
// to return itself as the first return value.
func SetGlobalRoutingFromBytes(fileBytes []byte) error {
	var err error
	globalRouter, err = router.NewFromConfigBytes(fileBytes)
	return err
}

// SetConfig implements the method for the KayveeLogger interface.
func (l *Logger) SetConfig(source string, logLvl LogLevel, formatter Formatter, output io.Writer) {
	l.globalsL.Lock()
	defer l.globalsL.Unlock()

	if l.globals == nil {
		l.globals = make(map[string]interface{})
	}
	l.globals["source"] = source
	l.logLvl = logLvl
	l.fLogger.setFormatter(formatter)
	l.fLogger.setOutput(output)
}

// AddContext implements the method for the KayveeLogger interface.
func (l *Logger) AddContext(key, val string) {
	l.globalsL.Lock()
	defer l.globalsL.Unlock()
	updateContextMapIfNotReserved(l.globals, key, val)
}

// GetContext implements the method for the KayveeLogger interface.
func (l *Logger) GetContext(key string) (interface{}, bool) {
	l.globalsL.RLock()
	defer l.globalsL.RUnlock()
	val, ok := l.globals[key]
	return val, ok
}

// SetRouter implements the method for the KayveeLogger interface.
func (l *Logger) SetRouter(router router.Router) {
	l.logRouter = router
}

// SetLogLevel implements the method for the KayveeLogger interface.
func (l *Logger) SetLogLevel(logLvl LogLevel) {
	l.logLvl = logLvl
}

// SetFormatter implements the method for the KayveeLogger interface.
func (l *Logger) SetFormatter(formatter Formatter) {
	l.fLogger.setFormatter(formatter)
}

// SetOutput implements the method for the KayveeLogger interface.
func (l *Logger) SetOutput(output io.Writer) {
	l.fLogger.setOutput(output)
}

func (l *Logger) setFormatLogger(fl formatLogger) {
	l.fLogger = fl
}

// Trace implements the method for the KayveeLogger interface.
func (l *Logger) Trace(title string) {
	l.TraceD(title, M{})
}

// Debug implements the method for the KayveeLogger interface.
func (l *Logger) Debug(title string) {
	l.DebugD(title, M{})
}

// Info implements the method for the KayveeLogger interface.
func (l *Logger) Info(title string) {
	l.InfoD(title, M{})
}

// Warn implements the method for the KayveeLogger interface.
func (l *Logger) Warn(title string) {
	l.WarnD(title, M{})
}

// Error implements the method for the KayveeLogger interface.
func (l *Logger) Error(title string) {
	l.ErrorD(title, M{})
}

// Critical implements the method for the KayveeLogger interface.
func (l *Logger) Critical(title string) {
	l.CriticalD(title, M{})
}

// Counter implements the method for the KayveeLogger interface.
// Logs with type = gauge, and value = value
func (l *Logger) Counter(title string) {
	l.CounterD(title, 1, M{}) // Defaults to a value of 1
}

// GaugeInt implements the method for the KayveeLogger interface.
// Logs with type = gauge, and value = value
func (l *Logger) GaugeInt(title string, value int) {
	l.GaugeIntD(title, value, M{})
}

// GaugeFloat implements the method for the KayveeLogger interface.
// Logs with type = gauge, and value = value
func (l *Logger) GaugeFloat(title string, value float64) {
	l.GaugeFloatD(title, value, M{})
}

// TraceD implements the method for the KayveeLogger interface.
func (l *Logger) TraceD(title string, data map[string]interface{}) {
	data["title"] = title
	l.logWithLevel(Trace, data)
}

// DebugD implements the method for the KayveeLogger interface.
func (l *Logger) DebugD(title string, data map[string]interface{}) {
	data["title"] = title
	l.logWithLevel(Debug, data)
}

// InfoD implements the method for the KayveeLogger interface.
func (l *Logger) InfoD(title string, data map[string]interface{}) {
	data["title"] = title
	l.logWithLevel(Info, data)
}

// WarnD implements the method for the KayveeLogger interface.
func (l *Logger) WarnD(title string, data map[string]interface{}) {
	data["title"] = title
	l.logWithLevel(Warning, data)
}

// ErrorD implements the method for the KayveeLogger interface.
func (l *Logger) ErrorD(title string, data map[string]interface{}) {
	data["title"] = title
	l.logWithLevel(Error, data)
}

// CriticalD implements the method for the KayveeLogger interface.
func (l *Logger) CriticalD(title string, data map[string]interface{}) {
	data["title"] = title
	l.logWithLevel(Critical, data)
}

// CounterD implements the method for the KayveeLogger interface.
// Logs with type = up/down counter, and value = value
func (l *Logger) CounterD(title string, value int, data map[string]interface{}) {
	if l.metricsOutput == otlMetrics {
		l.globalsL.RLock()
		meter := global.Meter(fmt.Sprintf("%s", l.globals["source"]))
		l.globalsL.RUnlock()
		// Use a Int64UpDownCounter counter instead of a Int64Counter DataDog chose not to follow the OTEL spec
		// this causes the first add to not be counted and reported
		// https://github.com/open-telemetry/opentelemetry-collector-contrib/issues/3654
		counter, err := meter.AsyncInt64().UpDownCounter(title)
		if err != nil {
			data["CounterD-error"] = err.Error()
			l.logWithLevel(Error, data)
		}
		counter.Observe(context.Background(), int64(value), getLabels(data)...)
	} else {
		data["title"] = title
		data["value"] = value
		data["type"] = "counter"
		l.logWithLevel(Info, data)
	}
}

// GaugeIntD implements the method for the KayveeLogger interface.
// Logs with type = gauge, and value = value
func (l *Logger) GaugeIntD(title string, value int, data map[string]interface{}) {
	l.gauge(title, value, data)
}

// GaugeFloatD implements the method for the KayveeLogger interface.
// Logs with type = gauge, and value = value
func (l *Logger) GaugeFloatD(title string, value float64, data map[string]interface{}) {
	l.gauge(title, value, data)
}

// Timer implements the method for the KayveeLogger interface.
// Returns Timer structure with .Stop method
func (l *Logger) Timer(title string) *Timer {
	return l.TimerD(title, M{})
}

// TimerD implements the method for the KayveeLogger interface.
// Returns Timer structure with .Stop method
func (l *Logger) TimerD(title string, data map[string]interface{}) *Timer {
	l.DebugD(title+"-start", data)
	return &Timer{Logger: l, StartedAt: time.Now(), Title: title}
}

func (l *Logger) gauge(title string, value interface{}, data map[string]interface{}) {
	if l.metricsOutput == otlMetrics {
		ctx := context.Background()
		l.globalsL.RLock()
		meter := global.Meter(fmt.Sprintf("%s", l.globals["source"]))
		l.globalsL.RUnlock()
		switch v := value.(type) {
		case int:
			m, err := meter.SyncInt64().Histogram(title)
			if err != nil {
				data["gauge-error"] = err.Error()
				l.logWithLevel(Error, data)
			}
			m.Record(ctx, int64(v), getLabels(data)...)
		case float64:
			m, err := meter.SyncFloat64().Histogram(title)
			if err != nil {
				data["gauge-error"] = err.Error()
				l.logWithLevel(Error, data)
			}
			m.Record(ctx, v, getLabels(data)...)
		}
	} else {
		data["title"] = title
		data["value"] = value
		data["type"] = "gauge"
		l.logWithLevel(Info, data)
	}
}

// Actual logging. Handles whether to output based on log level and
// unifies the passed in data with the stored globals
func (l *Logger) logWithLevel(logLvl LogLevel, data map[string]interface{}) {
	if logLvl < l.logLvl {
		// No log output
		return
	}
	data["level"] = logLvl.String()
	l.globalsL.RLock()
	defer l.globalsL.RUnlock()
	for key, value := range l.globals {
		if _, ok := data[key]; ok {
			// Values in the data map override the globals
			continue
		}
		data[key] = value
	}
	if l.logRouter != nil {
		data["_kvmeta"] = l.logRouter.Route(data)
	} else if globalRouter != nil {
		data["_kvmeta"] = globalRouter.Route(data)
	}

	l.fLogger.formatAndLog(data)
}

// setupOtlMetrics sets up the opentelemetry metrics exporter.
// It takes in the host:port to connect to via TCP.
func setupOtlMetrics(hostPort string) error {
	conn, err := net.Dial("tcp", hostPort)
	if err == nil {
		conn.Close()
	} else {
		return fmt.Errorf("cannot connect to opentelemetry collector at %s: %s", hostPort, err)
	}

	ctx := context.Background()
	otlClient := otlpmetricgrpc.NewClient(
		otlpmetricgrpc.WithInsecure(),
	)

	exp, err := otlpmetric.New(ctx, otlClient)
	if err != nil {
		return fmt.Errorf("failed to create the otel collector exporter: %v", err)
	}

	// get app data
	var appName, buildID, deployEnv string
	if os.Getenv("_POD_ID") != "" {
		appName = os.Getenv("_APP_NAME")
		buildID = os.Getenv("_BUILD_ID")
		deployEnv = os.Getenv("_DEPLOY_ENV")
	} else if os.Getenv("POD_ID") != "" {
		appName = os.Getenv("APP_NAME")
		buildID = os.Getenv("BUILD_ID")
		deployEnv = os.Getenv("DEPLOY_ENV")
	}

	pusher := otlController.New(
		otlProcessor.NewFactory(
			simple.NewWithInexpensiveDistribution(),
			exp,
		),
		otlController.WithExporter(exp),
		otlController.WithCollectPeriod(2*time.Second),
		otlController.WithResource(resource.NewSchemaless(
			attribute.String("service.name", appName),
			attribute.String("service.version", buildID),
			attribute.String("deployment.environment", deployEnv),
		)),
	)
	globalOTLController = pusher
	global.SetMeterProvider(pusher)

	if err := pusher.Start(ctx); err != nil {
		return fmt.Errorf("could not start metric controller: %v", err)
	}
	c := make(chan os.Signal, 1)
	signal.Notify(c, os.Interrupt, os.Signal(syscall.SIGTERM))
	go func() {
		for range c {
			teardownOTLMetrics()
		}
	}()
	return nil
}

// teardownOTLMetrics handles closing all connections and pushes the queued metrics
func teardownOTLMetrics() error {
	if globalOTLController != nil {
		return globalOTLController.Stop(context.Background())
	}
	return nil
}

// updateContextMapIfNotReserved updates context[key] to val if key is not in the reserved list.
func updateContextMapIfNotReserved(context M, key string, val interface{}) {
	if reservedKeyNames[strings.ToLower(key)] {
		log.Printf("WARN: kayvee logger reserves '%s' from being set as context", key)
		return
	}
	context[key] = val
}

// New creates a *logger.Logger. Default values are Debug LogLevel, kayvee Formatter, and std.err output.
// Deprecated: use NewConcreteLogger instead
func New(source string) KayveeLogger {
	return NewWithContext(source, nil)
}

// NewWithContext creates a *logger.Logger. Default values are Debug LogLevel, kayvee Formatter, and std.err output.
func NewWithContext(source string, contextValues map[string]interface{}) KayveeLogger {
	return NewConcreteLoggerWithContext(source, contextValues)
}

/////////////////////////////
//
//	FormatLogger
//
/////////////////////////////

// formatLogger is an interface that abstracts the last steps in submitting a log
// message to a Logger: formatting and log writing. It can be replaced for testing.
// This is not yet exported, but could be if clients want customization of the
// format and writing steps.
type formatLogger interface {
	// formatAndLog processes the given data map into a log line and writes it
	formatAndLog(data map[string]interface{})

	// setFormatter specifies the Formatter function to use in formatAndLog
	setFormatter(formatter Formatter)

	// setOutput specifies the output destination to use in formatAndLog
	setOutput(output io.Writer)
}

// defaultFormatLogger provides default implementation of a formatLogger.
type defaultFormatLogger struct {
	formatter Formatter
	logWriter *log.Logger
}

// formatAndLog implements the formatLogger interface for *defaultFormatLogger.
func (fl *defaultFormatLogger) formatAndLog(data map[string]interface{}) {
	logString := fl.formatter(data)
	fl.logWriter.Println(logString)
}

// setFormat implements the formatLogger interface for *defaultFormatLogger.
func (fl *defaultFormatLogger) setFormatter(formatter Formatter) {
	fl.formatter = formatter
}

// setOutput implements the formatLogger interface for *defaultFormatLogger.
func (fl *defaultFormatLogger) setOutput(output io.Writer) {
	fl.logWriter = log.New(output, "", 0) // No prefixes
}

// getLabels takes a M{} and returns an array of opentelemetry []attribute.KeyValue
func getLabels(data map[string]interface{}) []attribute.KeyValue {
	attrs := []attribute.KeyValue{}

	for k, v := range data {
		switch v := v.(type) {
		case int:
			attrs = append(attrs, attribute.Int(k, v))
		case int32:
			attrs = append(attrs, attribute.Int64(k, int64(v)))
		case int64:
			attrs = append(attrs, attribute.Int64(k, v))
		case float32:
			attrs = append(attrs, attribute.Float64(k, float64(v)))
		case float64:
			attrs = append(attrs, attribute.Float64(k, v))
		case string:
			attrs = append(attrs, attribute.String(k, v))
		case bool:
			attrs = append(attrs, attribute.Bool(k, v))
		default:
			attrs = append(attrs, attribute.String(k, fmt.Sprintf("%+v", v)))
		}
	}

	return attrs
}

// Log is a basic logging method that fulfills the WagClientLogger interface.
func (l *Logger) Log(level wcl.LogLevel, title string, m map[string]interface{}) {
	m["title"] = title
	l.logWithLevel(LogLevel(level), m)
}

// NewConcreteLogger creates a *logger.Logger. Default values are Debug LogLevel, kayvee Formatter, and std.err output.
func NewConcreteLogger(source string) *Logger {
	return NewConcreteLoggerWithContext(source, nil)
}

// NewConcreteLoggerWithContext creates a *logger.Logger. Default values are Debug LogLevel, kayvee Formatter, and std.err output.
func NewConcreteLoggerWithContext(source string, contextValues M) *Logger {
	ctx := M{}
	for k, v := range contextValues {
		updateContextMapIfNotReserved(ctx, k, v)
	}
	if teamName := os.Getenv("_TEAM_OWNER"); teamName != "" {
		ctx["team"] = teamName
	} else if teamName := os.Getenv("TEAM_OWNER"); teamName != "" {
		ctx["team"] = teamName
	}
	if v := os.Getenv("_DEPLOY_ENV"); v != "" {
		ctx["deploy_env"] = v
	} else if v := os.Getenv("DEPLOY_ENV"); v != "" {
		ctx["deploy_env"] = v
	}
	if os.Getenv("_EXECUTION_NAME") != "" {
		ctx["wf_id"] = os.Getenv("_EXECUTION_NAME")
	}
	if os.Getenv("_POD_ID") != "" {
		ctx["pod-id"] = os.Getenv("_POD_ID")
	}
	if os.Getenv("_POD_SHORTNAME") != "" {
		ctx["pod-shortname"] = os.Getenv("_POD_SHORTNAME")
	}
	if os.Getenv("_POD_REGION") != "" {
		ctx["pod-region"] = os.Getenv("_POD_REGION")
	}
	if os.Getenv("_POD_ACCOUNT") != "" {
		ctx["pod-account"] = os.Getenv("_POD_ACCOUNT")
	}
	logObj := Logger{
		globals: ctx,
	}

	if globalOTLController != nil {
		logObj.metricsOutput = otlMetrics
	} else {
		logObj.metricsOutput = logMetrics
	}

	fl := defaultFormatLogger{}
	logObj.fLogger = &fl

	var logLvl LogLevel
	strLogLvl := os.Getenv("KAYVEE_LOG_LEVEL")
	if strLogLvl == "" {
		logLvl = Trace
	} else {
		for key, val := range logLevelNames {
			if strings.ToLower(strLogLvl) == val {
				logLvl = key
				break
			}
		}
	}

	logObj.SetConfig(source, logLvl, kv.Format, os.Stderr)

	return &logObj

}