diff --git a/daemon/log_ring.go b/daemon/log_ring.go new file mode 100644 index 00000000..f59e9cc2 --- /dev/null +++ b/daemon/log_ring.go @@ -0,0 +1,39 @@ +package daemon + +import ( + "github.com/sagernet/sing-box/log" +) + +type logRing struct { + entries []*log.Entry + maxLines int + start int +} + +func (r *logRing) push(entry *log.Entry) { + if r.maxLines <= 0 { + return + } + if len(r.entries) < r.maxLines { + r.entries = append(r.entries, entry) + return + } + r.entries[r.start] = entry + r.start++ + if r.start == len(r.entries) { + r.start = 0 + } +} + +func (r *logRing) array() []*log.Entry { + result := make([]*log.Entry, 0, len(r.entries)) + result = append(result, r.entries[r.start:]...) + result = append(result, r.entries[:r.start]...) + return result +} + +func (r *logRing) reset() { + clear(r.entries) + r.entries = r.entries[:0] + r.start = 0 +} diff --git a/daemon/started_service.go b/daemon/started_service.go index c9f8f884..5e8c7998 100644 --- a/daemon/started_service.go +++ b/daemon/started_service.go @@ -23,7 +23,6 @@ import ( "github.com/sagernet/sing/common" "github.com/sagernet/sing/common/memory" "github.com/sagernet/sing/common/observable" - "github.com/sagernet/sing/common/x/list" "github.com/sagernet/sing/service" "github.com/gofrs/uuid/v5" @@ -47,7 +46,6 @@ type StartedService struct { // platform adapter.PlatformInterface handler PlatformHandler debug bool - logMaxLines int oomKillerEnabled bool oomKillerDisabled bool oomMemoryLimit uint64 @@ -64,7 +62,7 @@ type StartedService struct { serviceStatusSubscriber *observable.Subscriber[*ServiceStatus] serviceStatusObserver *observable.Observer[*ServiceStatus] logAccess sync.RWMutex - logLines list.List[*log.Entry] + logLines logRing logSubscriber *observable.Subscriber[*log.Entry] logObserver *observable.Observer[*log.Entry] instance *Instance @@ -99,7 +97,7 @@ func NewStartedService(options ServiceOptions) *StartedService { // platform: options.Platform, handler: options.Handler, debug: options.Debug, - logMaxLines: options.LogMaxLines, + logLines: logRing{maxLines: options.LogMaxLines}, oomKillerEnabled: options.OOMKillerEnabled, oomKillerDisabled: options.OOMKillerDisabled, oomMemoryLimit: options.OOMMemoryLimit, @@ -140,7 +138,7 @@ func (s *StartedService) GetVersion(ctx context.Context, empty *emptypb.Empty) ( func (s *StartedService) resetLogs() { s.logAccess.Lock() - s.logLines = list.List[*log.Entry]{} + s.logLines.reset() s.logAccess.Unlock() s.logSubscriber.Emit(nil) } @@ -378,12 +376,8 @@ func (s *StartedService) SubscribeServiceStatus(empty *emptypb.Empty, server grp } func (s *StartedService) SubscribeLog(empty *emptypb.Empty, server grpc.ServerStreamingServer[Log]) error { - var savedLines []*log.Entry s.logAccess.Lock() - savedLines = make([]*log.Entry, 0, s.logLines.Len()) - for element := s.logLines.Front(); element != nil; element = element.Next() { - savedLines = append(savedLines, element.Value) - } + savedLines := s.logLines.array() subscription, done, err := s.logObserver.Subscribe() s.logAccess.Unlock() if err != nil { @@ -2092,10 +2086,7 @@ func (s *StartedService) mustEmbedUnimplementedStartedServiceServer() { func (s *StartedService) WriteMessage(level log.Level, message string) { item := &log.Entry{Level: level, Message: message} s.logAccess.Lock() - s.logLines.PushBack(item) - if s.logLines.Len() > s.logMaxLines { - s.logLines.Remove(s.logLines.Front()) - } + s.logLines.push(item) s.logAccess.Unlock() s.logSubscriber.Emit(item) if s.debug { @@ -2106,7 +2097,7 @@ func (s *StartedService) WriteMessage(level log.Level, message string) { func (s *StartedService) SavedLog() []*log.Entry { s.logAccess.RLock() defer s.logAccess.RUnlock() - return s.logLines.Array() + return s.logLines.array() } func (s *StartedService) Instance() *Instance { diff --git a/log/format.go b/log/format.go index 6f4347b1..4ffa9e54 100644 --- a/log/format.go +++ b/log/format.go @@ -6,8 +6,6 @@ import ( "strings" "time" - F "github.com/sagernet/sing/common/format" - "github.com/logrusorgru/aurora" ) @@ -20,155 +18,171 @@ type Formatter struct { DisableLineBreak bool } -func (f Formatter) Format(ctx context.Context, level Level, tag string, message string, timestamp time.Time) string { - levelString := strings.ToUpper(FormatLevel(level)) - if !f.DisableColors { +var ( + levelLabels [LevelTrace + 1]string + coloredLevelLabels [LevelTrace + 1]string +) + +func init() { + for level := LevelPanic; level <= LevelTrace; level++ { + label := strings.ToUpper(FormatLevel(level)) + levelLabels[level] = label switch level { case LevelDebug, LevelTrace: - levelString = aurora.White(levelString).String() + coloredLevelLabels[level] = aurora.White(label).String() case LevelInfo: - levelString = aurora.Cyan(levelString).String() + coloredLevelLabels[level] = aurora.Cyan(label).String() case LevelWarn: - levelString = aurora.Yellow(levelString).String() + coloredLevelLabels[level] = aurora.Yellow(label).String() case LevelError, LevelFatal, LevelPanic: - levelString = aurora.Red(levelString).String() + coloredLevelLabels[level] = aurora.Red(label).String() } } - if tag != "" { - message = tag + ": " + message - } +} + +func (f Formatter) Format(ctx context.Context, level Level, tag string, message string, timestamp time.Time) string { var id ID var hasId bool if ctx != nil { id, hasId = IDFromContext(ctx) } + var builder strings.Builder + builder.Grow(len(tag) + len(message) + 64) + f.writePrefix(&builder, level, timestamp) if hasId { - activeDuration := FormatDuration(time.Since(id.CreatedAt)) - if !f.DisableColors { - var color aurora.Color - color = aurora.Color(uint8(id.ID)) - color %= 215 - row := uint(color / 36) - column := uint(color % 36) - - var r, g, b float32 - r = float32(row * 51) - g = float32(column / 6 * 51) - b = float32((column % 6) * 51) - luma := 0.2126*r + 0.7152*g + 0.0722*b - if luma < 60 { - row = 5 - row - column = 35 - column - color = aurora.Color(row*36 + column) - } - color += 16 - color = color << 16 - color |= 1 << 14 - message = F.ToString("[", aurora.Colorize(id.ID, color).String(), " ", activeDuration, "] ", message) - } else { - message = F.ToString("[", id.ID, " ", activeDuration, "] ", message) - } + f.writeIdPrefix(&builder, id) } - switch { - case f.DisableTimestamp: - message = levelString + " " + message - case f.FullTimestamp: - message = timestamp.Format(f.TimestampFormat) + " " + levelString + " " + message - default: - message = levelString + "[" + xd(int(timestamp.Sub(f.BaseTime)/time.Second), 4) + "] " + message + if tag != "" { + builder.WriteString(tag) + builder.WriteString(": ") } if f.DisableLineBreak { - if message[len(message)-1] == '\n' { - message = message[:len(message)-1] - } + builder.WriteString(strings.TrimSuffix(message, "\n")) } else { - if message[len(message)-1] != '\n' { - message += "\n" + builder.WriteString(message) + if !strings.HasSuffix(message, "\n") { + builder.WriteByte('\n') } } - return message + return builder.String() } -func (f Formatter) FormatWithSimple(ctx context.Context, level Level, tag string, message string, timestamp time.Time) (string, string) { - levelString := strings.ToUpper(FormatLevel(level)) - if !f.DisableColors { - switch level { - case LevelDebug, LevelTrace: - levelString = aurora.White(levelString).String() - case LevelInfo: - levelString = aurora.Cyan(levelString).String() - case LevelWarn: - levelString = aurora.Yellow(levelString).String() - case LevelError, LevelFatal, LevelPanic: - levelString = aurora.Red(levelString).String() - } - } - if tag != "" { - message = tag + ": " + message - } - messageSimple := message +func (f Formatter) FormatSimple(ctx context.Context, tag string, message string) string { var id ID var hasId bool if ctx != nil { id, hasId = IDFromContext(ctx) } + if !hasId && tag == "" { + return message + } + var builder strings.Builder + builder.Grow(len(tag) + len(message) + 32) if hasId { - activeDuration := FormatDuration(time.Since(id.CreatedAt)) - if !f.DisableColors { - var color aurora.Color - color = aurora.Color(uint8(id.ID)) - color %= 215 - row := uint(color / 36) - column := uint(color % 36) - - var r, g, b float32 - r = float32(row * 51) - g = float32(column / 6 * 51) - b = float32((column % 6) * 51) - luma := 0.2126*r + 0.7152*g + 0.0722*b - if luma < 60 { - row = 5 - row - column = 35 - column - color = aurora.Color(row*36 + column) - } - color += 16 - color = color << 16 - color |= 1 << 14 - message = F.ToString("[", aurora.Colorize(id.ID, color).String(), " ", activeDuration, "] ", message) - } else { - message = F.ToString("[", id.ID, " ", activeDuration, "] ", message) - } - messageSimple = F.ToString("[", id.ID, " ", activeDuration, "] ", messageSimple) + builder.WriteByte('[') + writeUint(&builder, uint64(id.ID)) + builder.WriteByte(' ') + writeDuration(&builder, time.Since(id.CreatedAt)) + builder.WriteString("] ") + } + if tag != "" { + builder.WriteString(tag) + builder.WriteString(": ") + } + builder.WriteString(message) + return builder.String() +} +func (f Formatter) writePrefix(builder *strings.Builder, level Level, timestamp time.Time) { + var levelString string + if int(level) >= len(levelLabels) { + levelString = "UNKNOWN" + } else if f.DisableColors { + levelString = levelLabels[level] + } else { + levelString = coloredLevelLabels[level] } switch { case f.DisableTimestamp: - message = levelString + " " + message + builder.WriteString(levelString) + builder.WriteByte(' ') case f.FullTimestamp: - message = timestamp.Format(f.TimestampFormat) + " " + levelString + " " + message + var timeBuffer [64]byte + builder.Write(timestamp.AppendFormat(timeBuffer[:0], f.TimestampFormat)) + builder.WriteByte(' ') + builder.WriteString(levelString) + builder.WriteByte(' ') default: - message = levelString + "[" + xd(int(timestamp.Sub(f.BaseTime)/time.Second), 4) + "] " + message + builder.WriteString(levelString) + builder.WriteByte('[') + seconds := strconv.AppendInt(make([]byte, 0, 20), int64(timestamp.Sub(f.BaseTime)/time.Second), 10) + for pad := 4 - len(seconds); pad > 0; pad-- { + builder.WriteByte('0') + } + builder.Write(seconds) + builder.WriteString("] ") } - if message[len(message)-1] != '\n' { - message += "\n" - } - return message, messageSimple } -func xd(value int, x int) string { - message := strconv.Itoa(value) - for len(message) < x { - message = "0" + message +func (f Formatter) writeIdPrefix(builder *strings.Builder, id ID) { + builder.WriteByte('[') + if f.DisableColors { + writeUint(builder, uint64(id.ID)) + } else { + builder.WriteString("\x1b[38;5;") + writeUint(builder, uint64(colorForID(id.ID))) + builder.WriteByte('m') + writeUint(builder, uint64(id.ID)) + builder.WriteString("\x1b[0m") + } + builder.WriteByte(' ') + writeDuration(builder, time.Since(id.CreatedAt)) + builder.WriteString("] ") +} + +func colorForID(value uint32) uint8 { + color := uint8(value) % 215 + row := uint(color / 36) + column := uint(color % 36) + r := float32(row * 51) + g := float32(column / 6 * 51) + b := float32((column % 6) * 51) + luma := 0.2126*r + 0.7152*g + 0.0722*b + if luma < 60 { + row = 5 - row + column = 35 - column + color = uint8(row*36 + column) + } + return color + 16 +} + +func writeUint(builder *strings.Builder, value uint64) { + builder.Write(strconv.AppendUint(make([]byte, 0, 20), value, 10)) +} + +func writeInt(builder *strings.Builder, value int64) { + builder.Write(strconv.AppendInt(make([]byte, 0, 20), value, 10)) +} + +func writeDuration(builder *strings.Builder, duration time.Duration) { + if duration < time.Second { + writeInt(builder, duration.Milliseconds()) + builder.WriteString("ms") + } else if duration < time.Minute { + writeInt(builder, int64(duration.Seconds())) + builder.WriteByte('.') + writeInt(builder, int64(duration.Seconds()*100)%100) + builder.WriteByte('s') + } else { + writeInt(builder, int64(duration.Minutes())) + builder.WriteByte('m') + writeInt(builder, int64(duration.Seconds())%60) + builder.WriteByte('s') } - return message } func FormatDuration(duration time.Duration) string { - if duration < time.Second { - return F.ToString(duration.Milliseconds(), "ms") - } else if duration < time.Minute { - return F.ToString(int64(duration.Seconds()), ".", int64(duration.Seconds()*100)%100, "s") - } else { - return F.ToString(int64(duration.Minutes()), "m", int64(duration.Seconds())%60, "s") - } + var builder strings.Builder + writeDuration(&builder, duration) + return builder.String() } diff --git a/log/observable.go b/log/observable.go index a11d4f73..ab50e56b 100644 --- a/log/observable.go +++ b/log/observable.go @@ -24,6 +24,7 @@ type defaultFactory struct { file *os.File filePath string platformWriters atomic.Pointer[[]PlatformWriter] + needConsole bool needObservable bool level Level subscriber *observable.Subscriber[Entry] @@ -58,6 +59,7 @@ func NewDefaultFactory( }, writer: writer, filePath: filePath, + needConsole: writer != io.Discard || filePath != "", needObservable: needObservable, level: LevelTrace, subscriber: observable.NewSubscriber[Entry](128), @@ -81,6 +83,7 @@ func (f *defaultFactory) Start() error { f.writer = logFile f.file = logFile } + f.needConsole = f.writer != io.Discard } if f.needObservable { f.observer = observable.NewObserver[Entry](f.subscriber, 64) @@ -144,19 +147,7 @@ func (f *defaultFactory) UnSubscribe(sub observable.Subscription[Entry]) { } 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 { + if level <= f.level && (f.needConsole || level == LevelPanic || level == LevelFatal) { formatted := f.formatter.Format(ctx, level, tag, message, timestamp) if level == LevelPanic { panic(formatted) @@ -166,6 +157,9 @@ func (f *defaultFactory) output(ctx context.Context, level Level, tag string, me os.Exit(1) } } + if f.needObservable { + f.subscriber.Emit(Entry{level, f.formatter.FormatSimple(ctx, tag, message)}) + } platformWriters := f.loadPlatformWriters() if len(platformWriters) > 0 { platformMessage := f.platformFormatter.Format(ctx, level, tag, message, timestamp)