[service] Move logging to the core

base/api/endpoints_debug.go

@@ -12,6 +12,7 @@ import (
 	"time"
 
 	"github.com/safing/portmaster/base/info"
+	"github.com/safing/portmaster/base/log"
 	"github.com/safing/portmaster/base/utils/debug"
 )
 
@@ -152,12 +153,12 @@ func getStack(_ *Request) (data []byte, err error) {
 
 // printStack prints the current goroutine stack to stderr.
 func printStack(_ *Request) (msg string, err error) {
-	_, err = fmt.Fprint(os.Stderr, "===== PRINTING STACK =====\n")
+	_, err = fmt.Fprint(log.GlobalWriter, "===== PRINTING STACK =====\n")
 	if err == nil {
 		err = pprof.Lookup("goroutine").WriteTo(os.Stderr, 1)
 	}
 	if err == nil {
-		_, err = fmt.Fprint(os.Stderr, "===== END OF STACK =====\n")
+		_, err = fmt.Fprint(log.GlobalWriter, "===== END OF STACK =====\n")
 	}
 	if err != nil {
 		return "", err

base/log/logging.go

@@ -2,6 +2,7 @@ package log
 
 import (
 	"fmt"
+	"log/slog"
 	"os"
 	"strings"
 	"sync"
@@ -33,6 +34,26 @@ import (
 // Severity describes a log level.
 type Severity uint32
 
+func (s Severity) toSLogLevel() slog.Level {
+	// Convert to slog level.
+	switch s {
+	case TraceLevel:
+		return slog.LevelDebug
+	case DebugLevel:
+		return slog.LevelDebug
+	case InfoLevel:
+		return slog.LevelInfo
+	case WarningLevel:
+		return slog.LevelWarn
+	case ErrorLevel:
+		return slog.LevelError
+	case CriticalLevel:
+		return slog.LevelError
+	}
+	// Failed to convert, return default log level
+	return slog.LevelWarn
+}
+
 // Message describes a log level message and is implemented
 // by logLine.
 type Message interface {
@@ -187,13 +208,17 @@ func ParseLevel(level string) Severity {
 }
 
 // Start starts the logging system. Must be called in order to see logs.
-func Start() (err error) {
+func Start(level Severity) (err error) {
 	if !initializing.SetToIf(false, true) {
 		return nil
 	}
 
-	logBuffer = make(chan *logLine, 1024)
+	atomic.StoreUint32(logLevel, uint32(level))
 
+	// Initialize slog
+	setupSLog(level)
+
+	// Parse command line log level argument
 	if logLevelFlag != "" {
 		initialLogLevel := ParseLevel(logLevelFlag)
 		if initialLogLevel == 0 {
@@ -202,11 +227,10 @@ func Start() (err error) {
 		}
 
 		SetLogLevel(initialLogLevel)
-	} else {
-		// Setup slog here for the transition period.
-		setupSLog(GetLogLevel())
 	}
 
+	logBuffer = make(chan *logLine, 1024)
+
 	// get and set file loglevels
 	pkgLogLevels := pkgLogLevelsFlag
 	if len(pkgLogLevels) > 0 {
@@ -246,4 +270,5 @@ func Shutdown() {
 		close(shutdownSignal)
 	}
 	shutdownWaitGroup.Wait()
+	GlobalWriter.Close()
 }

base/log/output.go

@@ -2,78 +2,25 @@ package log
 
 import (
 	"fmt"
-	"os"
 	"runtime/debug"
 	"sync"
 	"time"
-)
-
-type (
-	// Adapter is used to write logs.
-	Adapter interface {
-		// Write is called for each log message.
-		Write(msg Message, duplicates uint64)
-	}
-
-	// AdapterFunc is a convenience type for implementing
-	// Adapter.
-	AdapterFunc func(msg Message, duplicates uint64)
-
-	// FormatFunc formats msg into a string.
-	FormatFunc func(msg Message, duplicates uint64) string
 
-	// SimpleFileAdapter implements Adapter and writes all
-	// messages to File.
-	SimpleFileAdapter struct {
-		Format FormatFunc
-		File   *os.File
-	}
+	"github.com/safing/portmaster/base/info"
 )
 
-var (
-	// StdoutAdapter is a simple file adapter that writes
-	// all logs to os.Stdout using a predefined format.
-	StdoutAdapter = &SimpleFileAdapter{
-		File:   os.Stdout,
-		Format: defaultColorFormater,
-	}
-
-	// StderrAdapter is a simple file adapter that writes
-	// all logs to os.Stdout using a predefined format.
-	StderrAdapter = &SimpleFileAdapter{
-		File:   os.Stderr,
-		Format: defaultColorFormater,
-	}
-)
+// Adapter is used to write logs.
+type Adapter interface {
+	// Write is called for each log message.
+	WriteMessage(msg Message, duplicates uint64)
+}
 
 var (
-	adapter Adapter = StdoutAdapter
-
 	schedulingEnabled = false
 	writeTrigger      = make(chan struct{})
 )
 
-// SetAdapter configures the logging adapter to use.
-// This must be called before the log package is initialized.
-func SetAdapter(a Adapter) {
-	if initializing.IsSet() || a == nil {
-		return
-	}
-
-	adapter = a
-}
-
-// Write implements Adapter and calls fn.
-func (fn AdapterFunc) Write(msg Message, duplicates uint64) {
-	fn(msg, duplicates)
-}
-
-// Write implements Adapter and writes msg the underlying file.
-func (fileAdapter *SimpleFileAdapter) Write(msg Message, duplicates uint64) {
-	fmt.Fprintln(fileAdapter.File, fileAdapter.Format(msg, duplicates))
-}
-
-// EnableScheduling enables external scheduling of the logger. This will require to manually trigger writes via TriggerWrite whenevery logs should be written. Please note that full buffers will also trigger writing. Must be called before Start() to have an effect.
+// EnableScheduling enables external scheduling of the logger. This will require to manually trigger writes via TriggerWrite whenever logs should be written. Please note that full buffers will also trigger writing. Must be called before Start() to have an effect.
 func EnableScheduling() {
 	if !initializing.IsSet() {
 		schedulingEnabled = true
@@ -95,27 +42,47 @@ func TriggerWriterChannel() chan struct{} {
 	return writeTrigger
 }
 
-func defaultColorFormater(line Message, duplicates uint64) string {
-	return formatLine(line.(*logLine), duplicates, true) //nolint:forcetypeassert // TODO: improve
-}
-
 func startWriter() {
-	fmt.Printf(
-		"%s%s%s %sBOF %s%s\n",
-
-		dimColor(),
-		time.Now().Format(timeFormat),
-		endDimColor(),
-
-		blueColor(),
-		rightArrow,
-		endColor(),
-	)
+	if GlobalWriter.isStdout {
+		fmt.Fprintf(GlobalWriter,
+			"%s%s%s %sBOF %s%s\n",
+
+			dimColor(),
+			time.Now().Format(timeFormat),
+			endDimColor(),
+
+			blueColor(),
+			rightArrow,
+			endColor(),
+		)
+	} else {
+		fmt.Fprintf(GlobalWriter,
+			"%s BOF %s\n",
+			time.Now().Format(timeFormat),
+			rightArrow,
+		)
+	}
+	writeVersion()
 
 	shutdownWaitGroup.Add(1)
 	go writerManager()
 }
 
+func writeVersion() {
+	if GlobalWriter.isStdout {
+		fmt.Fprintf(GlobalWriter, "%s%s%s Running version: %s%s%s\n",
+			dimColor(),
+			time.Now().Format(timeFormat),
+			endDimColor(),
+
+			blueColor(),
+			info.Version(),
+			endColor())
+	} else {
+		fmt.Fprintf(GlobalWriter, "%s Running version: %s\n", time.Now().Format(timeFormat), info.Version())
+	}
+}
+
 func writerManager() {
 	defer shutdownWaitGroup.Done()
 
@@ -129,18 +96,17 @@ func writerManager() {
 	}
 }
 
-// defer should be able to edit the err. So naked return is required.
-// nolint:golint,nakedret
-func writer() (err error) {
+func writer() error {
+	var err error
 	defer func() {
 		// recover from panic
 		panicVal := recover()
 		if panicVal != nil {
-			err = fmt.Errorf("%s", panicVal)
+			_, err = fmt.Fprintf(GlobalWriter, "%s", panicVal)
 
 			// write stack to stderr
 			fmt.Fprintf(
-				os.Stderr,
+				GlobalWriter,
 				`===== Error Report =====
 Message: %s
 StackTrace:
@@ -169,7 +135,7 @@ StackTrace:
 		case <-forceEmptyingOfBuffer: // log buffer is full!
 		case <-shutdownSignal: // shutting down
 			finalizeWriting()
-			return
+			return err
 		}
 
 		// wait for timeslot to log
@@ -178,7 +144,7 @@ StackTrace:
 		case <-forceEmptyingOfBuffer: // log buffer is full!
 		case <-shutdownSignal: // shutting down
 			finalizeWriting()
-			return
+			return err
 		}
 
 		// write all the logs!
@@ -201,7 +167,7 @@ StackTrace:
 				}
 
 				// if currentLine and line are _not_ equal, output currentLine
-				adapter.Write(currentLine, duplicates)
+				GlobalWriter.WriteMessage(currentLine, duplicates)
 				// add to unexpected logs
 				addUnexpectedLogs(currentLine)
 				// reset duplicate counter
@@ -215,7 +181,7 @@ StackTrace:
 
 		// write final line
 		if currentLine != nil {
-			adapter.Write(currentLine, duplicates)
+			GlobalWriter.WriteMessage(currentLine, duplicates)
 			// add to unexpected logs
 			addUnexpectedLogs(currentLine)
 		}
@@ -225,7 +191,7 @@ StackTrace:
 		case <-time.After(10 * time.Millisecond):
 		case <-shutdownSignal:
 			finalizeWriting()
-			return
+			return err
 		}
 
 	}
@@ -235,19 +201,27 @@ func finalizeWriting() {
 	for {
 		select {
 		case line := <-logBuffer:
-			adapter.Write(line, 0)
+			GlobalWriter.WriteMessage(line, 0)
 		case <-time.After(10 * time.Millisecond):
-			fmt.Printf(
-				"%s%s%s %sEOF %s%s\n",
-
-				dimColor(),
-				time.Now().Format(timeFormat),
-				endDimColor(),
-
-				blueColor(),
-				leftArrow,
-				endColor(),
-			)
+			if GlobalWriter.isStdout {
+				fmt.Fprintf(GlobalWriter,
+					"%s%s%s %sEOF %s%s\n",
+
+					dimColor(),
+					time.Now().Format(timeFormat),
+					endDimColor(),
+
+					blueColor(),
+					leftArrow,
+					endColor(),
+				)
+			} else {
+				fmt.Fprintf(GlobalWriter,
+					"%s EOF %s\n",
+					time.Now().Format(timeFormat),
+					leftArrow,
+				)
+			}
 			return
 		}
 	}