From 9d8d4b8796a4f0133009c70802d67e17e6097504 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E4=B8=96=E7=95=8C?= Date: Fri, 21 Aug 2026 17:42:42 +0800 Subject: [PATCH] Fix log output before service started --- cmd/sing-box/cmd.go | 5 ++- log/export.go | 8 +++- log/observable.go | 98 +++++++++++++++++++++++++++++++-------------- 3 files changed, 79 insertions(+), 32 deletions(-) diff --git a/cmd/sing-box/cmd.go b/cmd/sing-box/cmd.go index 575cb7a0..e635f5c0 100644 --- a/cmd/sing-box/cmd.go +++ b/cmd/sing-box/cmd.go @@ -10,6 +10,7 @@ import ( "github.com/sagernet/sing-box/experimental/deprecated" "github.com/sagernet/sing-box/include" "github.com/sagernet/sing-box/log" + "github.com/sagernet/sing/common" "github.com/sagernet/sing/service" "github.com/sagernet/sing/service/filemanager" @@ -52,7 +53,9 @@ func preRun(cmd *cobra.Command, args []string) { globalCtx = filemanager.WithDefault(globalCtx, "", "", sudoUID, sudoGID) } if disableColor { - log.SetStdLogger(log.NewDefaultFactory(context.Background(), log.Formatter{BaseTime: time.Now(), DisableColors: true}, os.Stderr, "", nil, false).Logger()) + logFactory := log.NewDefaultFactory(context.Background(), log.Formatter{BaseTime: time.Now(), DisableColors: true}, os.Stderr, "", nil, false) + common.Must(logFactory.Start()) + log.SetStdLogger(logFactory.Logger()) } if workingDir != "" { _, err := os.Stat(workingDir) diff --git a/log/export.go b/log/export.go index 60a0abbb..a5850814 100644 --- a/log/export.go +++ b/log/export.go @@ -4,19 +4,23 @@ import ( "context" "os" "time" + + "github.com/sagernet/sing/common" ) var std ContextLogger func init() { - std = NewDefaultFactory( + factory := NewDefaultFactory( context.Background(), Formatter{BaseTime: time.Now()}, os.Stderr, "", nil, false, - ).Logger() + ) + common.Must(factory.Start()) + std = factory.Logger() } func StdLogger() ContextLogger { diff --git a/log/observable.go b/log/observable.go index efb2450e..eb05e290 100644 --- a/log/observable.go +++ b/log/observable.go @@ -4,6 +4,8 @@ import ( "context" "io" "os" + "sync" + "sync/atomic" "time" "github.com/sagernet/sing/common" @@ -26,6 +28,17 @@ type defaultFactory struct { level Level subscriber *observable.Subscriber[Entry] observer *observable.Observer[Entry] + startAccess sync.Mutex + started atomic.Bool + pendingEntries []pendingEntry +} + +type pendingEntry struct { + ctx context.Context + level Level + tag string + message string + timestamp time.Time } func NewDefaultFactory( @@ -60,18 +73,31 @@ func NewDefaultFactory( } func (f *defaultFactory) Start() error { + var err error if f.filePath != "" { - logFile, err := filemanager.OpenFile(f.ctx, f.filePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) - if err != nil { - return err + logFile, openErr := filemanager.OpenFile(f.ctx, f.filePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) + if openErr != nil { + err = openErr + } else { + f.writer = logFile + f.file = logFile } - f.writer = logFile - f.file = logFile } - return nil + f.startAccess.Lock() + pendingEntries := f.pendingEntries + f.pendingEntries = nil + f.started.Store(true) + f.startAccess.Unlock() + for _, entry := range pendingEntries { + f.output(entry.ctx, entry.level, entry.tag, entry.message, entry.timestamp) + } + return err } func (f *defaultFactory) Close() error { + f.startAccess.Lock() + f.pendingEntries = nil + f.startAccess.Unlock() return common.Close( common.PtrOrNil(f.file), f.subscriber, @@ -102,6 +128,34 @@ func (f *defaultFactory) UnSubscribe(sub observable.Subscription[Entry]) { f.observer.UnSubscribe(sub) } +func (f *defaultFactory) output(ctx context.Context, level Level, tag string, message string, timestamp time.Time) { + if f.needObservable { + formatted, formattedSimple := f.formatter.FormatWithSimple(ctx, level, tag, message, timestamp) + if level <= f.level { + if level == LevelPanic { + panic(formatted) + } + f.writer.Write([]byte(formatted)) + if level == LevelFatal { + os.Exit(1) + } + } + f.subscriber.Emit(Entry{level, formattedSimple}) + } else if level <= f.level { + formatted := f.formatter.Format(ctx, level, tag, message, timestamp) + if level == LevelPanic { + panic(formatted) + } + f.writer.Write([]byte(formatted)) + if level == LevelFatal { + os.Exit(1) + } + } + if f.platformWriter != nil { + f.platformWriter.WriteMessage(level, f.platformFormatter.Format(ctx, level, tag, message, timestamp)) + } +} + var _ ContextLogger = (*observableLogger)(nil) type observableLogger struct { @@ -115,31 +169,17 @@ func (l *observableLogger) Log(ctx context.Context, level Level, args []any) { return } nowTime := time.Now() - if l.needObservable { - message, messageSimple := l.formatter.FormatWithSimple(ctx, level, l.tag, F.ToString(args...), nowTime) - if level <= l.level { - if level == LevelPanic { - panic(message) - } - l.writer.Write([]byte(message)) - if level == LevelFatal { - os.Exit(1) - } - } - l.subscriber.Emit(Entry{level, messageSimple}) - } else if level <= l.level { - message := l.formatter.Format(ctx, level, l.tag, F.ToString(args...), nowTime) - if level == LevelPanic { - panic(message) - } - l.writer.Write([]byte(message)) - if level == LevelFatal { - os.Exit(1) + message := F.ToString(args...) + if !l.started.Load() && level != LevelFatal && level != LevelPanic { + l.startAccess.Lock() + if !l.started.Load() { + l.pendingEntries = append(l.pendingEntries, pendingEntry{ctx, level, l.tag, message, nowTime}) + l.startAccess.Unlock() + return } + l.startAccess.Unlock() } - if l.platformWriter != nil { - l.platformWriter.WriteMessage(level, l.platformFormatter.Format(ctx, level, l.tag, F.ToString(args...), nowTime)) - } + l.output(ctx, level, l.tag, message, nowTime) } func (l *observableLogger) Trace(args ...any) {