proxy: add configurable logging timestamp format (#401)

introduces a new configuration option logTimeFormat that allows customizing the timestamp in log messages using golang's built in time format constants. The default remains no timestamp.

config-schema.json

@@ -59,6 +59,29 @@
             "default": "info",
             "description": "Sets the logging value. Valid values: debug, info, warn, error."
         },
+        "logTimeFormat": {
+            "type": "string",
+            "enum": [
+                "",
+                "ansic",
+                "unixdate",
+                "rubydate",
+                "rfc822",
+                "rfc822z",
+                "rfc850",
+                "rfc1123",
+                "rfc1123z",
+                "rfc3339",
+                "rfc3339nano",
+                "kitchen",
+                "stamp",
+                "stampmilli",
+                "stampmicro",
+                "stampnano"
+            ],
+            "default": "",
+            "description": "Enables and sets the logging timestamp format. Valid values: \"\", \"ansic\", \"unixdate\", \"rubydate\", \"rfc822\", \"rfc822z\", \"rfc850\", \"rfc1123\", \"rfc1123z\", \"rfc3339\", \"rfc3339nano\", \"kitchen\", \"stamp\", \"stampmilli\", \"stampmicro\", and \"stampnano\". For more info, read: https://pkg.go.dev/time#pkg-constants"
+        },
         "metricsMaxInMemory": {
             "type": "integer",
             "default": 1000,

config.example.yaml

@@ -26,6 +26,14 @@ healthCheckTimeout: 500
 # - Valid log levels: debug, info, warn, error
 logLevel: info
 
+# logTimeFormat: enables and sets the logging timestamp format
+# - optional, default (disabled): ""
+# - Valid values: "", "ansic", "unixdate", "rubydate", "rfc822", "rfc822z",
+#   "rfc850", "rfc1123", "rfc1123z", "rfc3339", "rfc3339nano", "kitchen",
+#   "stamp", "stampmilli", "stampmicro", and "stampnano".
+# - For more info, read: https://pkg.go.dev/time#pkg-constants
+logTimeFormat: ""
+
 # metricsMaxInMemory: maximum number of metrics to keep in memory
 # - optional, default: 1000
 # - controls how many metrics are stored in memory before older ones are discarded

proxy/config/config.go

@@ -113,6 +113,7 @@ type Config struct {
 	HealthCheckTimeout int                    `yaml:"healthCheckTimeout"`
 	LogRequests        bool                   `yaml:"logRequests"`
 	LogLevel           string                 `yaml:"logLevel"`
+	LogTimeFormat      string                 `yaml:"logTimeFormat"`
 	MetricsMaxInMemory int                    `yaml:"metricsMaxInMemory"`
 	Models             map[string]ModelConfig `yaml:"models"` /* key is model ID */
 	Profiles           map[string][]string    `yaml:"profiles"`
@@ -175,6 +176,7 @@ func LoadConfigFromReader(r io.Reader) (Config, error) {
 		HealthCheckTimeout: 120,
 		StartPort:          5800,
 		LogLevel:           "info",
+		LogTimeFormat:      "",
 		MetricsMaxInMemory: 1000,
 	}
 	err = yaml.Unmarshal(data, &config)

proxy/config/config_posix_test.go

@@ -58,6 +58,7 @@ models:
 	assert.Equal(t, 120, config.HealthCheckTimeout)
 	assert.Equal(t, 5800, config.StartPort)
 	assert.Equal(t, "info", config.LogLevel)
+	assert.Equal(t, "", config.LogTimeFormat)
 
 	// Test default group exists
 	defaultGroup, exists := config.Groups["(default)"]
@@ -163,8 +164,9 @@ groups:
 	modelLoadingState := false
 
 	expected := Config{
-		LogLevel:  "info",
+		LogLevel:      "info",
-		StartPort: 5800,
+		LogTimeFormat: "",
+		StartPort:     5800,
 		Macros: MacroList{
 			{"svr-path", "path/to/server"},
 		},

proxy/config/config_windows_test.go

@@ -55,6 +55,7 @@ models:
 	assert.Equal(t, 120, config.HealthCheckTimeout)
 	assert.Equal(t, 5800, config.StartPort)
 	assert.Equal(t, "info", config.LogLevel)
+	assert.Equal(t, "", config.LogTimeFormat)
 
 	// Test default group exists
 	defaultGroup, exists := config.Groups["(default)"]
@@ -155,8 +156,9 @@ groups:
 	modelLoadingState := false
 
 	expected := Config{
-		LogLevel:  "info",
+		LogLevel:      "info",
-		StartPort: 5800,
+		LogTimeFormat: "",
+		StartPort:     5800,
 		Macros: MacroList{
 			{"svr-path", "path/to/server"},
 		},

proxy/logMonitor.go

@@ -7,6 +7,7 @@ import (
 	"io"
 	"os"
 	"sync"
+	"time"
 
 	"github.com/mostlygeek/llama-swap/event"
 )
@@ -32,6 +33,9 @@ type LogMonitor struct {
 	// logging levels
 	level  LogLevel
 	prefix string
+
+	// timestamps
+	timeFormat string
 }
 
 func NewLogMonitor() *LogMonitor {
@@ -40,11 +44,12 @@ func NewLogMonitor() *LogMonitor {
 
 func NewLogMonitorWriter(stdout io.Writer) *LogMonitor {
 	return &LogMonitor{
-		eventbus: event.NewDispatcherConfig(1000),
+		eventbus:   event.NewDispatcherConfig(1000),
-		buffer:   ring.New(10 * 1024), // keep 10KB of buffered logs
+		buffer:     ring.New(10 * 1024), // keep 10KB of buffered logs
-		stdout:   stdout,
+		stdout:     stdout,
-		level:    LevelInfo,
+		level:      LevelInfo,
-		prefix:   "",
+		prefix:     "",
+		timeFormat: "",
 	}
 }
 
@@ -106,12 +111,22 @@ func (w *LogMonitor) SetLogLevel(level LogLevel) {
 	w.level = level
 }
 
+func (w *LogMonitor) SetLogTimeFormat(timeFormat string) {
+	w.mu.Lock()
+	defer w.mu.Unlock()
+	w.timeFormat = timeFormat
+}
+
 func (w *LogMonitor) formatMessage(level string, msg string) []byte {
 	prefix := ""
 	if w.prefix != "" {
 		prefix = fmt.Sprintf("[%s] ", w.prefix)
 	}
-	return []byte(fmt.Sprintf("%s[%s] %s\n", prefix, level, msg))
+	timestamp := ""
+	if w.timeFormat != "" {
+		timestamp = fmt.Sprintf("%s ", time.Now().Format(w.timeFormat))
+	}
+	return []byte(fmt.Sprintf("%s%s[%s] %s\n", timestamp, prefix, level, msg))
 }
 
 func (w *LogMonitor) log(level LogLevel, msg string) {

proxy/logMonitor_test.go

@@ -3,8 +3,10 @@ package proxy
 import (
 	"bytes"
 	"io"
+	"strings"
 	"sync"
 	"testing"
+	"time"
 )
 
 func TestLogMonitor(t *testing.T) {
@@ -84,3 +86,30 @@ func TestWrite_ImmutableBuffer(t *testing.T) {
 		t.Errorf("Expected history to be %q, got %q", expected, history)
 	}
 }
+
+func TestWrite_LogTimeFormat(t *testing.T) {
+	// Create a new LogMonitor instance
+	lm := NewLogMonitorWriter(io.Discard)
+
+	// Enable timestamps
+	lm.timeFormat = time.RFC3339
+
+	// Write the message to the LogMonitor
+	lm.Info("Hello, World!")
+
+	// Get the history from the LogMonitor
+	history := lm.GetHistory()
+
+	timestamp := ""
+	fields := strings.Fields(string(history))
+	if len(fields) > 0 {
+		timestamp = fields[0]
+	} else {
+		t.Fatalf("Cannot extract string from history")
+	}
+
+	_, err := time.Parse(time.RFC3339, timestamp)
+	if err != nil {
+		t.Fatalf("Cannot find timestamp: %v", err)
+	}
+}

proxy/proxymanager.go

@@ -75,6 +75,30 @@ func New(config config.Config) *ProxyManager {
 		upstreamLogger.SetLogLevel(LevelInfo)
 	}
 
+	// see: https://go.dev/src/time/format.go
+	timeFormats := map[string]string{
+		"ansic":       time.ANSIC,
+		"unixdate":    time.UnixDate,
+		"rubydate":    time.RubyDate,
+		"rfc822":      time.RFC822,
+		"rfc822z":     time.RFC822Z,
+		"rfc850":      time.RFC850,
+		"rfc1123":     time.RFC1123,
+		"rfc1123z":    time.RFC1123Z,
+		"rfc3339":     time.RFC3339,
+		"rfc3339nano": time.RFC3339Nano,
+		"kitchen":     time.Kitchen,
+		"stamp":       time.Stamp,
+		"stampmilli":  time.StampMilli,
+		"stampmicro":  time.StampMicro,
+		"stampnano":   time.StampNano,
+	}
+
+	if timeFormat, ok := timeFormats[strings.ToLower(strings.TrimSpace(config.LogTimeFormat))]; ok {
+		proxyLogger.SetLogTimeFormat(timeFormat)
+		upstreamLogger.SetLogTimeFormat(timeFormat)
+	}
+
 	shutdownCtx, shutdownCancel := context.WithCancel(context.Background())
 
 	var maxMetrics int