diff --git a/daemon/managed_service.go b/daemon/managed_service.go index 14c2bd57..dfc986cb 100644 --- a/daemon/managed_service.go +++ b/daemon/managed_service.go @@ -6,7 +6,6 @@ import ( "unsafe" "github.com/sagernet/sing-box/service/oomkiller" - "github.com/sagernet/sing/common/memory" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" @@ -18,20 +17,20 @@ var _ ManagedServiceServer = (*ManagedService)(nil) type ManagedService struct { handler ManagedHandler debug bool - oomReporter oomkiller.OOMReporter + oomRecorder *oomkiller.Recorder } type ManagedServiceOptions struct { Handler ManagedHandler Debug bool - OOMReporter oomkiller.OOMReporter + OOMRecorder *oomkiller.Recorder } func NewManagedService(options ManagedServiceOptions) *ManagedService { return &ManagedService{ handler: options.Handler, debug: options.Debug, - oomReporter: options.OOMReporter, + oomRecorder: options.OOMRecorder, } } @@ -87,10 +86,10 @@ func (s *ManagedService) TriggerDebugCrash(ctx context.Context, request *DebugCr } func (s *ManagedService) TriggerOOMReport(ctx context.Context, _ *emptypb.Empty) (*emptypb.Empty, error) { - if s.oomReporter == nil { - return nil, status.Error(codes.Unavailable, "OOM reporter not available") + if s.oomRecorder == nil { + return nil, status.Error(codes.Unavailable, "OOM recorder not available") } - return &emptypb.Empty{}, s.oomReporter.WriteReport(memory.Total()) + return &emptypb.Empty{}, s.oomRecorder.WriteReport() } func (s *ManagedService) mustEmbedUnimplementedManagedServiceServer() { diff --git a/experimental/boxdd/server.go b/experimental/boxdd/server.go index 583a25b5..8e9f6b16 100644 --- a/experimental/boxdd/server.go +++ b/experimental/boxdd/server.go @@ -33,6 +33,7 @@ type Daemon struct { logger log.ContextLogger startedService *daemon.StartedService powerManager *powerreport.Manager + oomRecorder *oomkiller.Recorder server *grpc.Server runtimeWorkingDirectory string lifecycleAccess sync.Mutex @@ -63,14 +64,15 @@ func newDaemon() (*Daemon, error) { Context: ctx, LogMaxLines: 3000, }) - reporter := libbox.NewOOMReporter(d.startedService) - service.MustRegister[oomkiller.OOMReporter](ctx, reporter) + d.oomRecorder = oomkiller.NewRecorder(libbox.OOMRecorderOptions(d.startedService)) + service.MustRegister[*oomkiller.Recorder](ctx, d.oomRecorder) + d.oomRecorder.Start() d.powerManager = powerreport.NewManager() service.MustRegister[*powerreport.Manager](ctx, d.powerManager) managedService := daemon.NewManagedService(daemon.ManagedServiceOptions{ Handler: &managedHandler{d}, Debug: debugEnabled, - OOMReporter: reporter, + OOMRecorder: d.oomRecorder, }) authorizer := newAuthorizer(d) serverOptions := []grpc.ServerOption{ @@ -289,6 +291,7 @@ func (d *Daemon) Close() { } _ = d.startedService.CloseService() d.startedService.Close() + _ = d.oomRecorder.Close() if d.platform != nil { _ = d.platform.Close() } diff --git a/experimental/libbox/command_server.go b/experimental/libbox/command_server.go index 2391b74e..c75c4ccd 100644 --- a/experimental/libbox/command_server.go +++ b/experimental/libbox/command_server.go @@ -36,6 +36,7 @@ type CommandServer struct { platformInterface PlatformInterface platformWrapper *platformInterfaceWrapper powerManager *powerreport.Manager + oomRecorder *oomkiller.Recorder grpcServer *grpc.Server listener net.Listener endPauseTimer *time.Timer @@ -83,12 +84,14 @@ func NewCommandServer(handler CommandServerHandler, platformInterface PlatformIn // GroupID: sGroupID, // SystemProxyEnabled: false, }) - reporter := &oomReporter{startedService: server.StartedService} - service.MustRegister[oomkiller.OOMReporter](ctx, reporter) + oomRecorder := oomkiller.NewRecorder(OOMRecorderOptions(server.StartedService)) + service.MustRegister[*oomkiller.Recorder](ctx, oomRecorder) + oomRecorder.Start() + server.oomRecorder = oomRecorder server.managedService = daemon.NewManagedService(daemon.ManagedServiceOptions{ Handler: (*platformHandler)(server), Debug: sDebug, - OOMReporter: reporter, + OOMRecorder: oomRecorder, }) if sPowerReportEnabled { err := powerManager.Start(PowerReportOptions(server.StartedService)) @@ -195,6 +198,7 @@ func (s *CommandServer) Close() { } common.Close(s.listener) s.StartedService.Close() + s.oomRecorder.Close() s.powerManager.Close() } diff --git a/experimental/libbox/internal/oomprofile/oomprofile.go b/experimental/libbox/internal/oomprofile/oomprofile.go index 0728af8f..5d355337 100644 --- a/experimental/libbox/internal/oomprofile/oomprofile.go +++ b/experimental/libbox/internal/oomprofile/oomprofile.go @@ -7,7 +7,6 @@ import ( "io" "math" "os" - "path/filepath" "runtime" "sort" "strings" @@ -52,28 +51,27 @@ type labelMap struct { labelSet } -func WriteFile(destPath string, name string) (string, error) { +func WriteFile(filePath string, name string) error { writer, ok := profileWriters[name] if !ok { - return "", fmt.Errorf("unsupported profile %q", name) + return fmt.Errorf("unsupported profile %q", name) } - - filePath := filepath.Join(destPath, name+".pb") file, err := os.Create(filePath) if err != nil { - return "", err + return err } defer file.Close() - - if err := writer(file); err != nil { + err = writer(file) + if err != nil { _ = os.Remove(filePath) - return "", err + return err } - if err := file.Close(); err != nil { + err = file.Close() + if err != nil { _ = os.Remove(filePath) - return "", err + return err } - return filePath, nil + return nil } var profileWriters = map[string]func(io.Writer) error{ diff --git a/experimental/libbox/internal/runtimeinfo/goroutine_badlinkname.go b/experimental/libbox/internal/runtimeinfo/goroutine_badlinkname.go new file mode 100644 index 00000000..90b06054 --- /dev/null +++ b/experimental/libbox/internal/runtimeinfo/goroutine_badlinkname.go @@ -0,0 +1,172 @@ +//go:build badlinkname + +package runtimeinfo + +import ( + "bytes" + "cmp" + "reflect" + "runtime" + "slices" + "strconv" + "sync" + "sync/atomic" + "unsafe" +) + +// Mirrors runtime.g of the pinned Go toolchain up to goid; the offsets of gopc and startpc are +// discovered by probeGoroutine. + +type runtimeG struct { + stackLo uintptr + stackHi uintptr + _ [2]uintptr + _ [3]unsafe.Pointer + _ [6]uintptr + _ [4]uintptr + _ unsafe.Pointer + atomicstatus uint32 + _ uint32 + goid uint64 +} + +//go:linkname allgs runtime.allgs +var allgs []*runtimeG + +const probeScanBytes = 512 + +var ( + gopcOffset uintptr + startpcOffset uintptr + probeDone chan bool +) + +func (gp *runtimeG) word(offset uintptr) uintptr { + return *(*uintptr)(unsafe.Add(unsafe.Pointer(gp), offset)) +} + +func (gp *runtimeG) gopc() uintptr { + return gp.word(gopcOffset) +} + +func (gp *runtimeG) startpc() uintptr { + return gp.word(startpcOffset) +} + +const ( + statusDead = 6 + statusScan = 0x1000 +) + +var statusNames = map[uint32]string{ + 0: "idle", + 1: "runnable", + 2: "running", + 3: "syscall", + 4: "waiting", + 6: "dead", + 8: "copystack", + 9: "preempted", +} + +var ( + layoutOnce sync.Once + layoutVerified bool +) + +func probeLayout() { + probeDone = make(chan bool, 1) + go probeGoroutine() + layoutVerified = <-probeDone +} + +func probeGoroutine() { + id := currentGoroutineID() + var self *runtimeG + for _, gp := range allgs { + if gp.goid == id { + self = gp + break + } + } + if self == nil { + probeDone <- false + return + } + creatorName := functionName(reflect.ValueOf(probeLayout).Pointer()) + selfName := functionName(reflect.ValueOf(probeGoroutine).Pointer()) + goidOffset := unsafe.Offsetof(self.goid) + for offset := goidOffset + 8; offset < goidOffset+probeScanBytes; offset += 8 { + name := functionName(self.word(offset)) + if gopcOffset == 0 && name == creatorName { + gopcOffset = offset + } else if startpcOffset == 0 && name == selfName { + startpcOffset = offset + } + } + probeDone <- gopcOffset != 0 && startpcOffset != 0 +} + +func functionName(pc uintptr) string { + function := runtime.FuncForPC(pc) + if function == nil { + return "unknown" + } + return function.Name() +} + +func currentGoroutineID() uint64 { + var stackBuffer [64]byte + n := runtime.Stack(stackBuffer[:], false) + fields := bytes.Fields(stackBuffer[:n]) + if len(fields) < 2 { + return 0 + } + id, _ := strconv.ParseUint(string(fields[1]), 10, 64) + return id +} + +func collectGoroutines() *GoroutineReport { + layoutOnce.Do(probeLayout) + if !layoutVerified { + return nil + } + report := &GoroutineReport{ByStatus: make(map[string]int)} + groups := make(map[string]*GoroutineGroup) + for _, gp := range allgs { + status := atomic.LoadUint32(&gp.atomicstatus) &^ statusScan + stackSize := uint64(gp.stackHi - gp.stackLo) + if status == statusDead { + report.Dead++ + if gp.stackLo != 0 { + report.DeadStackBytes += stackSize + } + continue + } + report.Total++ + report.StackBytes += stackSize + statusName, known := statusNames[status] + if !known { + statusName = strconv.Itoa(int(status)) + } + report.ByStatus[statusName]++ + name := functionName(gp.startpc()) + group, found := groups[name] + if !found { + group = &GoroutineGroup{Function: name, CreatedBy: functionName(gp.gopc()), MinStackBytes: stackSize} + groups[name] = group + } + group.Count++ + group.StackBytes += stackSize + group.MaxStackBytes = max(group.MaxStackBytes, stackSize) + group.MinStackBytes = min(group.MinStackBytes, stackSize) + } + report.ByFunction = make([]GoroutineGroup, 0, len(groups)) + for _, group := range groups { + report.ByFunction = append(report.ByFunction, *group) + } + slices.SortFunc(report.ByFunction, func(a, b GoroutineGroup) int { + return cmp.Compare(b.StackBytes, a.StackBytes) + }) + return report +} diff --git a/experimental/libbox/internal/runtimeinfo/goroutine_stub.go b/experimental/libbox/internal/runtimeinfo/goroutine_stub.go new file mode 100644 index 00000000..e76ef398 --- /dev/null +++ b/experimental/libbox/internal/runtimeinfo/goroutine_stub.go @@ -0,0 +1,7 @@ +//go:build !badlinkname + +package runtimeinfo + +func collectGoroutines() *GoroutineReport { + return nil +} diff --git a/experimental/libbox/internal/runtimeinfo/pool_badlinkname.go b/experimental/libbox/internal/runtimeinfo/pool_badlinkname.go new file mode 100644 index 00000000..3d4b9867 --- /dev/null +++ b/experimental/libbox/internal/runtimeinfo/pool_badlinkname.go @@ -0,0 +1,81 @@ +//go:build badlinkname + +package runtimeinfo + +import ( + "reflect" + "sync" + "sync/atomic" + "unsafe" + + "github.com/sagernet/sing/common/buf" +) + +// Mirrors sync.Pool, sync.poolLocal and sync.poolChainElt of the pinned Go toolchain. + +type syncPool struct { + local unsafe.Pointer + localSize uintptr + victim unsafe.Pointer + victimSize uintptr + _ func() any +} + +type poolLocal struct { + private [2]unsafe.Pointer + sharedHead unsafe.Pointer + _ unsafe.Pointer + _ [128 - 4*unsafe.Sizeof(uintptr(0))]byte +} + +type poolChainElt struct { + headTail uint64 + _ []unsafe.Pointer + _ unsafe.Pointer + prev unsafe.Pointer +} + +func collectBufferPools() []PoolReport { + allocator := reflect.ValueOf(buf.DefaultAllocator) + if allocator.Kind() != reflect.Pointer { + return nil + } + pools := allocator.Elem().FieldByName("buffers") + if !pools.IsValid() || pools.Kind() != reflect.Array || pools.Type().Elem() != reflect.TypeFor[sync.Pool]() { + return nil + } + if unsafe.Sizeof(syncPool{}) != unsafe.Sizeof(sync.Pool{}) || unsafe.Sizeof(poolLocal{}) != 128 { + return nil + } + result := make([]PoolReport, 0, pools.Len()) + for i := range pools.Len() { + pool := (*syncPool)(pools.Index(i).Addr().UnsafePointer()) + size := min(1<<(6+i), buf.MaxPooledBufferSize) + report := PoolReport{ + Size: size, + Cached: countPoolLocals(pool.local, pool.localSize), + Victim: countPoolLocals(pool.victim, pool.victimSize), + } + report.Bytes = uint64(report.Cached+report.Victim) * uint64(size) + result = append(result, report) + } + return result +} + +func countPoolLocals(locals unsafe.Pointer, count uintptr) int { + if locals == nil { + return 0 + } + var total int + for i := range count { + local := (*poolLocal)(unsafe.Add(locals, i*unsafe.Sizeof(poolLocal{}))) + if local.private[0] != nil { + total++ + } + for element := (*poolChainElt)(atomic.LoadPointer(&local.sharedHead)); element != nil; element = (*poolChainElt)(atomic.LoadPointer(&element.prev)) { + headTail := atomic.LoadUint64(&element.headTail) + total += int(uint32(headTail>>32) - uint32(headTail)) + } + } + return total +} diff --git a/experimental/libbox/internal/runtimeinfo/pool_stub.go b/experimental/libbox/internal/runtimeinfo/pool_stub.go new file mode 100644 index 00000000..f5db1c6d --- /dev/null +++ b/experimental/libbox/internal/runtimeinfo/pool_stub.go @@ -0,0 +1,7 @@ +//go:build !badlinkname + +package runtimeinfo + +func collectBufferPools() []PoolReport { + return nil +} diff --git a/experimental/libbox/internal/runtimeinfo/runtimeinfo.go b/experimental/libbox/internal/runtimeinfo/runtimeinfo.go new file mode 100644 index 00000000..b3a9b187 --- /dev/null +++ b/experimental/libbox/internal/runtimeinfo/runtimeinfo.go @@ -0,0 +1,74 @@ +package runtimeinfo + +import ( + "encoding/json" + "os" + "runtime/metrics" +) + +type Report struct { + Metrics map[string]uint64 `json:"metrics"` + Goroutines *GoroutineReport `json:"goroutines,omitempty"` + Pools []PoolReport `json:"bufferPools,omitempty"` +} + +type GoroutineReport struct { + Total int `json:"total"` + StackBytes uint64 `json:"stackBytes"` + Dead int `json:"dead"` + DeadStackBytes uint64 `json:"deadStackBytes"` + ByStatus map[string]int `json:"byStatus"` + ByFunction []GoroutineGroup `json:"byFunction"` +} + +type GoroutineGroup struct { + Function string `json:"function"` + CreatedBy string `json:"createdBy,omitempty"` + Count int `json:"count"` + StackBytes uint64 `json:"stackBytes"` + MaxStackBytes uint64 `json:"maxStackBytes"` + MinStackBytes uint64 `json:"minStackBytes"` +} + +type PoolReport struct { + Size int `json:"size"` + Cached int `json:"cached"` + Victim int `json:"victim"` + Bytes uint64 `json:"bytes"` +} + +func Collect() Report { + return Report{ + Metrics: collectMetrics(), + Goroutines: collectGoroutines(), + Pools: collectBufferPools(), + } +} + +func WriteFile(path string) error { + content, err := json.MarshalIndent(Collect(), "", " ") + if err != nil { + return err + } + return os.WriteFile(path, content, 0o666) +} + +func collectMetrics() map[string]uint64 { + descriptions := metrics.All() + samples := make([]metrics.Sample, 0, len(descriptions)) + for _, description := range descriptions { + if description.Kind != metrics.KindUint64 { + continue + } + samples = append(samples, metrics.Sample{Name: description.Name}) + } + metrics.Read(samples) + result := make(map[string]uint64, len(samples)) + for _, sample := range samples { + if sample.Value.Kind() != metrics.KindUint64 { + continue + } + result[sample.Name] = sample.Value.Uint64() + } + return result +} diff --git a/experimental/libbox/oom_report.go b/experimental/libbox/oom_report.go index d9bbbdd5..6cccdb46 100644 --- a/experimental/libbox/oom_report.go +++ b/experimental/libbox/oom_report.go @@ -5,21 +5,18 @@ package libbox import ( "bytes" "encoding/json" - "os" "path/filepath" - "runtime" "sort" - "strings" "time" "github.com/sagernet/sing-box/common/trafficcontrol" "github.com/sagernet/sing-box/daemon" "github.com/sagernet/sing-box/experimental/libbox/internal/oomprofile" + "github.com/sagernet/sing-box/experimental/libbox/internal/runtimeinfo" "github.com/sagernet/sing-box/log" "github.com/sagernet/sing-box/service/oomkiller" "github.com/sagernet/sing/common/byteformats" F "github.com/sagernet/sing/common/format" - "github.com/sagernet/sing/common/memory" ) var oomReportProfiles = []string{ @@ -34,157 +31,66 @@ var oomReportProfiles = []string{ type oomReportMetadata struct { reportMetadata RecordedAt string `json:"recordedAt"` + EndedAt string `json:"endedAt,omitempty"` + MemoryLimit string `json:"memoryLimit,omitempty"` MemoryUsage string `json:"memoryUsage"` AvailableMemory string `json:"availableMemory,omitempty"` - // Heap - HeapAlloc string `json:"heapAlloc,omitempty"` - HeapObjects uint64 `json:"heapObjects,omitempty,string"` - HeapInuse string `json:"heapInuse,omitempty"` - HeapIdle string `json:"heapIdle,omitempty"` - HeapReleased string `json:"heapReleased,omitempty"` - HeapSys string `json:"heapSys,omitempty"` - // Stack - StackInuse string `json:"stackInuse,omitempty"` - StackSys string `json:"stackSys,omitempty"` - // Runtime metadata - MSpanInuse string `json:"mSpanInuse,omitempty"` - MSpanSys string `json:"mSpanSys,omitempty"` - MCacheSys string `json:"mCacheSys,omitempty"` - BuckHashSys string `json:"buckHashSys,omitempty"` - GCSys string `json:"gcSys,omitempty"` - OtherSys string `json:"otherSys,omitempty"` - Sys string `json:"sys,omitempty"` - // GC & runtime - TotalAlloc string `json:"totalAlloc,omitempty"` - NumGC uint32 `json:"numGC,omitempty,string"` - NumGoroutine int `json:"numGoroutine,omitempty,string"` - NextGC string `json:"nextGC,omitempty"` - LastGC string `json:"lastGC,omitempty"` + Snapshots int `json:"snapshots,omitempty,string"` } -type oomReporter struct { - startedService *daemon.StartedService +func OOMRecorderOptions(startedService *daemon.StartedService) oomkiller.RecorderOptions { + return oomkiller.RecorderOptions{ + BasePath: sWorkingPath, + Logger: log.StdLogger(), + AcceptDraft: acceptOOMDraft, + MetadataCallback: func(status oomkiller.ReportStatus) any { + metadata := oomReportMetadata{ + reportMetadata: baseReportMetadata(), + RecordedAt: status.RecordedAt.UTC().Format(time.RFC3339), + MemoryUsage: byteformats.FormatMemoryBytes(status.PeakMemory), + Snapshots: status.Snapshots, + } + metadata.StartedAt = status.StartedAt.UTC().Format(time.RFC3339) + if !status.EndedAt.IsZero() { + metadata.EndedAt = status.EndedAt.UTC().Format(time.RFC3339) + } + if status.MemoryLimit > 0 { + metadata.MemoryLimit = byteformats.FormatMemoryBytes(status.MemoryLimit) + } + if status.AvailableKnown { + metadata.AvailableMemory = byteformats.FormatMemoryBytes(status.MinAvailable) + } + return metadata + }, + OwnerCallback: chownReport, + LogCallback: func() []byte { + return formatLogEntries(startedService.SavedLog()) + }, + SnapshotCallback: func(directory string, prefix string) { + for _, name := range oomReportProfiles { + writeOOMProfile(filepath.Join(directory, prefix+"."+name+".pb"), name) + } + runtimeInfoPath := filepath.Join(directory, prefix+".runtime.json") + err := runtimeinfo.WriteFile(runtimeInfoPath) + if err == nil { + chownReport(runtimeInfoPath) + } + copyConfigSnapshot(directory) + content := oomConnectionsContent(startedService) + if content != nil { + writeReportFile(directory, prefix+".connections.json", content) + } + }, + } } -var _ oomkiller.OOMReporter = (*oomReporter)(nil) - -func NewOOMReporter(startedService *daemon.StartedService) oomkiller.OOMReporter { - return &oomReporter{startedService: startedService} -} - -func (r *oomReporter) WriteReport(memoryUsage uint64) error { - draftPath := filepath.Join(sWorkingPath, "oom_draft") - draftInfo, err := os.Stat(draftPath) +func acceptOOMDraft(metadataContent []byte) bool { + var draftMetadata reportMetadata + err := json.Unmarshal(metadataContent, &draftMetadata) if err != nil { - if !os.IsNotExist(err) { - return err - } - draftInfo = nil + return false } - reportsDir := filepath.Join(sWorkingPath, "oom_reports") - err = os.MkdirAll(reportsDir, 0o777) - if err != nil { - return err - } - chownReport(reportsDir) - - destPath, err := nextAvailableReportPath(reportsDir, time.Now().UTC()) - if err != nil { - return err - } - err = r.writeSnapshot(destPath, memoryUsage) - if err != nil { - return err - } - return discardDraftIfCurrent(draftPath, draftInfo) -} - -func (r *oomReporter) WriteDraft(memoryUsage uint64) error { - draftPath := filepath.Join(sWorkingPath, "oom_draft") - os.RemoveAll(draftPath) - return r.writeSnapshot(draftPath, memoryUsage) -} - -func (r *oomReporter) DiscardDraft() error { - draftPath := filepath.Join(sWorkingPath, "oom_draft") - return os.RemoveAll(draftPath) -} - -func discardDraftIfCurrent(draftPath string, draftInfo os.FileInfo) error { - if draftInfo == nil { - return nil - } - currentInfo, err := os.Stat(draftPath) - if err != nil { - if os.IsNotExist(err) { - return nil - } - return err - } - if !os.SameFile(draftInfo, currentInfo) { - return nil - } - return os.RemoveAll(draftPath) -} - -func (r *oomReporter) writeSnapshot(destPath string, memoryUsage uint64) error { - now := time.Now().UTC() - err := os.MkdirAll(destPath, 0o777) - if err != nil { - return err - } - chownReport(destPath) - - for _, name := range oomReportProfiles { - writeOOMProfile(destPath, name) - } - - writeReportFile(destPath, "cmdline", []byte(strings.Join(os.Args, "\000"))) - - var memStats runtime.MemStats - runtime.ReadMemStats(&memStats) - - metadata := oomReportMetadata{ - reportMetadata: baseReportMetadata(), - RecordedAt: now.Format(time.RFC3339), - MemoryUsage: byteformats.FormatMemoryBytes(memoryUsage), - // Heap - HeapAlloc: byteformats.FormatMemoryBytes(memStats.HeapAlloc), - HeapObjects: memStats.HeapObjects, - HeapInuse: byteformats.FormatMemoryBytes(memStats.HeapInuse), - HeapIdle: byteformats.FormatMemoryBytes(memStats.HeapIdle), - HeapReleased: byteformats.FormatMemoryBytes(memStats.HeapReleased), - HeapSys: byteformats.FormatMemoryBytes(memStats.HeapSys), - // Stack - StackInuse: byteformats.FormatMemoryBytes(memStats.StackInuse), - StackSys: byteformats.FormatMemoryBytes(memStats.StackSys), - // Runtime metadata - MSpanInuse: byteformats.FormatMemoryBytes(memStats.MSpanInuse), - MSpanSys: byteformats.FormatMemoryBytes(memStats.MSpanSys), - MCacheSys: byteformats.FormatMemoryBytes(memStats.MCacheSys), - BuckHashSys: byteformats.FormatMemoryBytes(memStats.BuckHashSys), - GCSys: byteformats.FormatMemoryBytes(memStats.GCSys), - OtherSys: byteformats.FormatMemoryBytes(memStats.OtherSys), - Sys: byteformats.FormatMemoryBytes(memStats.Sys), - // GC & runtime - TotalAlloc: byteformats.FormatMemoryBytes(memStats.TotalAlloc), - NumGC: memStats.NumGC, - NumGoroutine: runtime.NumGoroutine(), - NextGC: byteformats.FormatMemoryBytes(memStats.NextGC), - } - if memStats.LastGC > 0 { - metadata.LastGC = time.Unix(0, int64(memStats.LastGC)).UTC().Format(time.RFC3339) - } - availableMemory := memory.Available() - if availableMemory > 0 { - metadata.AvailableMemory = byteformats.FormatMemoryBytes(availableMemory) - } - writeReportMetadata(destPath, metadata) - copyConfigSnapshot(destPath) - writeOOMLog(destPath, r.startedService.SavedLog()) - r.writeOOMConnections(destPath) - - return nil + return draftMetadata.AppVersion == sAppVersion && draftMetadata.AppMarketingVersion == sAppMarketingVersion } type oomConnectionsInfo struct { @@ -213,14 +119,14 @@ type oomConnectionInfo struct { Download string `json:"download,omitempty"` } -func (r *oomReporter) writeOOMConnections(destPath string) { - instance := r.startedService.Instance() +func oomConnectionsContent(startedService *daemon.StartedService) []byte { + instance := startedService.Instance() if instance == nil { - return + return nil } trafficManager := instance.TrafficManager() if trafficManager == nil { - return + return nil } connections := trafficManager.Connections() sort.Slice(connections, func(i, j int) bool { @@ -235,9 +141,9 @@ func (r *oomReporter) writeOOMConnections(destPath string) { } data, err := json.MarshalIndent(info, "", " ") if err != nil { - return + return nil } - writeReportFile(destPath, "connections.json", data) + return data } func buildOOMConnections(connections []*trafficcontrol.TrackerMetadata) []oomConnectionInfo { @@ -314,14 +220,6 @@ func formatLogEntries(entries []*log.Entry) []byte { return buffer.Bytes() } -func writeOOMLog(destPath string, entries []*log.Entry) { - content := formatLogEntries(entries) - if content == nil { - return - } - writeReportFile(destPath, "go.log", content) -} - func writeWithoutColors(buffer *bytes.Buffer, message string) { start := 0 for index := 0; index < len(message); { @@ -343,54 +241,18 @@ func writeWithoutColors(buffer *bytes.Buffer, message string) { buffer.WriteString(message[start:]) } -func writeOOMProfile(destPath string, name string) { - filePath, err := oomprofile.WriteFile(destPath, name) +func writeOOMProfile(filePath string, name string) { + err := oomprofile.WriteFile(filePath, name) if err != nil { return } chownReport(filePath) } -func promoteOOMDraftAt(workingPath string) { - draftPath := filepath.Join(workingPath, "oom_draft") - info, err := os.Stat(draftPath) - if err != nil || !info.IsDir() { - return - } - metadataContent, err := os.ReadFile(filepath.Join(draftPath, "metadata.json")) - if err != nil { - os.RemoveAll(draftPath) - return - } - var draftMetadata reportMetadata - err = json.Unmarshal(metadataContent, &draftMetadata) - if err != nil || draftMetadata.AppVersion != sAppVersion || draftMetadata.AppMarketingVersion != sAppMarketingVersion { - os.RemoveAll(draftPath) - return - } - reportsDir := filepath.Join(workingPath, "oom_reports") - initReportDir(reportsDir) - destPath, err := nextAvailableReportPath(reportsDir, info.ModTime().UTC()) - if err != nil { - os.RemoveAll(draftPath) - return - } - err = os.Rename(draftPath, destPath) - if err != nil { - os.RemoveAll(draftPath) - return - } - chownReport(destPath) -} - -func promoteOOMDraft() { - promoteOOMDraftAt(sWorkingPath) -} - func PromoteOOMDraft() { - promoteOOMDraft() + oomkiller.PromoteDraft(sWorkingPath, acceptOOMDraft) } func PromoteOOMDraftAt(workingPath string) { - promoteOOMDraftAt(workingPath) + oomkiller.PromoteDraft(workingPath, acceptOOMDraft) } diff --git a/experimental/libbox/power_report.go b/experimental/libbox/power_report.go index d78c72b1..29648cf6 100644 --- a/experimental/libbox/power_report.go +++ b/experimental/libbox/power_report.go @@ -3,6 +3,7 @@ package libbox import ( + "path/filepath" "time" "github.com/sagernet/sing-box/daemon" @@ -29,7 +30,7 @@ func PowerReportOptions(startedService *daemon.StartedService) powerreport.Optio }, ProfileCallback: func(path string) { for _, name := range oomReportProfiles { - writeOOMProfile(path, name) + writeOOMProfile(filepath.Join(path, name+".pb"), name) } }, } diff --git a/experimental/libbox/setup.go b/experimental/libbox/setup.go index 9c3390ad..a78cba54 100644 --- a/experimental/libbox/setup.go +++ b/experimental/libbox/setup.go @@ -92,6 +92,7 @@ func ReloadSetupOptions(options *SetupOptions) { if sOOMKillerEnabled { if sOOMMemoryLimit == 0 && C.IsIos { sOOMMemoryLimit = oomkiller.DefaultAppleNetworkExtensionMemoryLimit + debug.SetGCPercent(oomkiller.DefaultAppleNetworkExtensionGCPercent) } if sOOMMemoryLimit > 0 { debug.SetMemoryLimit(sOOMMemoryLimit * 4 / 5) diff --git a/service/oomkiller/lock_unix.go b/service/oomkiller/lock_unix.go new file mode 100644 index 00000000..677b20ff --- /dev/null +++ b/service/oomkiller/lock_unix.go @@ -0,0 +1,26 @@ +//go:build !windows + +package oomkiller + +import ( + "os" + "syscall" +) + +func lockDraft(path string) (*os.File, error) { + file, err := os.OpenFile(path, os.O_CREATE|os.O_RDWR, 0o666) + if err != nil { + return nil, err + } + err = syscall.Flock(int(file.Fd()), syscall.LOCK_EX|syscall.LOCK_NB) + if err != nil { + file.Close() + return nil, err + } + return file, nil +} + +func unlockDraft(file *os.File) { + syscall.Flock(int(file.Fd()), syscall.LOCK_UN) + file.Close() +} diff --git a/service/oomkiller/lock_windows.go b/service/oomkiller/lock_windows.go new file mode 100644 index 00000000..7a2767fe --- /dev/null +++ b/service/oomkiller/lock_windows.go @@ -0,0 +1,25 @@ +package oomkiller + +import ( + "os" + + "golang.org/x/sys/windows" +) + +func lockDraft(path string) (*os.File, error) { + file, err := os.OpenFile(path, os.O_CREATE|os.O_RDWR, 0o666) + if err != nil { + return nil, err + } + err = windows.LockFileEx(windows.Handle(file.Fd()), windows.LOCKFILE_EXCLUSIVE_LOCK|windows.LOCKFILE_FAIL_IMMEDIATELY, 0, 1, 0, &windows.Overlapped{}) + if err != nil { + file.Close() + return nil, err + } + return file, nil +} + +func unlockDraft(file *os.File) { + windows.UnlockFileEx(windows.Handle(file.Fd()), 0, 1, 0, &windows.Overlapped{}) + file.Close() +} diff --git a/service/oomkiller/policy.go b/service/oomkiller/policy.go index aa744301..31c4b790 100644 --- a/service/oomkiller/policy.go +++ b/service/oomkiller/policy.go @@ -10,7 +10,10 @@ import ( "github.com/sagernet/sing/service" ) -const DefaultAppleNetworkExtensionMemoryLimit = 50 * 1024 * 1024 +const ( + DefaultAppleNetworkExtensionMemoryLimit = 50 * 1024 * 1024 + DefaultAppleNetworkExtensionGCPercent = 50 +) type policyMode uint8 @@ -25,6 +28,19 @@ func (m policyMode) hasTimerMode() bool { return m != policyModeNone } +func (m policyMode) String() string { + switch m { + case policyModeMemoryLimit: + return "memory_limit" + case policyModeAvailable: + return "available" + case policyModeNetworkExtension: + return "network_extension" + default: + return "none" + } +} + func resolvePolicyMode(ctx context.Context, options option.OOMKillerServiceOptions) (uint64, policyMode) { platformInterface := service.FromContext[adapter.PlatformInterface](ctx) if C.IsIos && platformInterface != nil && platformInterface.UnderNetworkExtension() { diff --git a/service/oomkiller/promote.go b/service/oomkiller/promote.go new file mode 100644 index 00000000..6069624a --- /dev/null +++ b/service/oomkiller/promote.go @@ -0,0 +1,141 @@ +package oomkiller + +import ( + "bufio" + "encoding/json" + "io" + "os" + "path/filepath" + "strconv" + "strings" + "time" + + E "github.com/sagernet/sing/common/exceptions" +) + +func PromoteDraft(basePath string, accept func(metadataContent []byte) bool) { + draftPath := filepath.Join(basePath, DraftDirectoryName) + info, err := os.Stat(draftPath) + if err != nil || !info.IsDir() { + return + } + lockPath := filepath.Join(draftPath, lockFileName) + lock, err := lockDraft(lockPath) + if err != nil { + return + } + os.Remove(lockPath) + unlockDraft(lock) + if !draftNotable(draftPath) { + os.RemoveAll(draftPath) + return + } + if accept != nil { + metadataContent, readErr := os.ReadFile(filepath.Join(draftPath, metadataFileName)) + if readErr != nil || !accept(metadataContent) { + os.RemoveAll(draftPath) + return + } + } + promoteDirectory(draftPath, filepath.Join(basePath, ReportsDirectoryName)) +} + +func draftNotable(draftPath string) bool { + file, err := os.Open(filepath.Join(draftPath, eventsFileName)) + if err != nil { + return false + } + defer file.Close() + scanner := bufio.NewScanner(file) + scanner.Buffer(nil, 1<<20) + for scanner.Scan() { + var event struct { + Type string `json:"t"` + } + err = json.Unmarshal(scanner.Bytes(), &event) + if err != nil { + continue + } + switch event.Type { + case eventTypePressure, eventTypeReset, eventTypeSnapshot: + return true + } + } + return false +} + +func promoteDirectory(draftPath string, reportsPath string) { + info, err := os.Stat(draftPath) + if err != nil || !info.IsDir() { + return + } + err = os.MkdirAll(reportsPath, 0o777) + if err != nil { + return + } + destPath, err := nextAvailableReportPath(reportsPath, info.ModTime().UTC()) + if err != nil { + os.RemoveAll(draftPath) + return + } + err = os.Rename(draftPath, destPath) + if err != nil { + os.RemoveAll(draftPath) + } +} + +func nextAvailableReportPath(reportsDir string, timestamp time.Time) (string, error) { + destName := timestamp.Format("2006-01-02T15-04-05") + destPath := filepath.Join(reportsDir, destName) + _, err := os.Stat(destPath) + if os.IsNotExist(err) { + return destPath, nil + } + for i := 1; i <= 1000; i++ { + suffixedPath := filepath.Join(reportsDir, destName+"-"+strconv.Itoa(i)) + _, err = os.Stat(suffixedPath) + if os.IsNotExist(err) { + return suffixedPath, nil + } + } + return "", E.New("no available report path for ", destName) +} + +func copyDirectory(sourcePath string, destPath string) error { + entries, err := os.ReadDir(sourcePath) + if err != nil { + return err + } + err = os.MkdirAll(destPath, 0o777) + if err != nil { + return err + } + for _, entry := range entries { + if entry.IsDir() || strings.HasPrefix(entry.Name(), ".") { + continue + } + err = copyFile(filepath.Join(sourcePath, entry.Name()), filepath.Join(destPath, entry.Name())) + if err != nil { + return err + } + } + return nil +} + +func copyFile(sourcePath string, destPath string) error { + source, err := os.Open(sourcePath) + if err != nil { + return err + } + defer source.Close() + dest, err := os.OpenFile(destPath, os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0o666) + if err != nil { + return err + } + _, err = io.Copy(dest, source) + if err != nil { + dest.Close() + return err + } + return dest.Close() +} diff --git a/service/oomkiller/recorder.go b/service/oomkiller/recorder.go new file mode 100644 index 00000000..a8a089a9 --- /dev/null +++ b/service/oomkiller/recorder.go @@ -0,0 +1,558 @@ +package oomkiller + +import ( + "encoding/json" + "os" + "path/filepath" + "runtime" + "runtime/metrics" + "strconv" + "sync" + "time" + + E "github.com/sagernet/sing/common/exceptions" + "github.com/sagernet/sing/common/logger" + "github.com/sagernet/sing/common/memory" +) + +const ( + DraftDirectoryName = "oom_draft" + ReportsDirectoryName = "oom_reports" + + timelineFileName = "timeline.jsonl" + eventsFileName = "events.jsonl" + metadataFileName = "metadata.json" + logFileName = "go.log" + lockFileName = ".lock" + + normalSampleInterval = time.Minute + pressureSampleInterval = time.Second + denseSampleWindow = 2 * time.Minute + + pressureSnapshotMinInterval = time.Hour + resetSnapshotMinInterval = 10 * time.Minute + maxAutomaticSnapshots = 8 +) + +const ( + SnapshotReasonPressure = "pressure" + SnapshotReasonReset = "reset" + SnapshotReasonManual = "manual" + + resetReasonThreshold = "threshold" + resetReasonRate = "rate" + + eventTypeStart = "start" + eventTypeStop = "stop" + eventTypePressure = "pressure" + eventTypeState = "state" + eventTypeReset = "reset" + eventTypeSnapshot = "snapshot" + eventTypeReport = "report" +) + +type RecorderOptions struct { + BasePath string + Logger logger.Logger + AcceptDraft func(metadataContent []byte) bool + MetadataCallback func(status ReportStatus) any + OwnerCallback func(path string) + LogCallback func() []byte + SnapshotCallback func(directory string, prefix string) +} + +type ReportStatus struct { + StartedAt time.Time + RecordedAt time.Time + EndedAt time.Time + MemoryLimit uint64 + PeakMemory uint64 + MinAvailable uint64 + AvailableKnown bool + Snapshots int +} + +type Recorder struct { + basePath string + draftPath string + logger logger.Logger + acceptDraft func(metadataContent []byte) bool + metadataCallback func(status ReportStatus) any + ownerCallback func(path string) + logCallback func() []byte + snapshotCallback func(directory string, prefix string) + + access sync.Mutex + started bool + closed bool + draftCreated bool + draftLock *os.File + notable bool + status ReportStatus + lastRowAt time.Time + lastRowState pressureState + hasRow bool + denseUntil time.Time + previousGCCycles uint64 + metricsSamples []metrics.Sample + + snapshotAccess sync.Mutex + snapshotSequence int + automaticSnapshots int + lastSnapshotAt map[string]time.Time +} + +type timelineRow struct { + At string `json:"at"` + State string `json:"state"` + MemoryBytes uint64 `json:"memoryBytes"` + AvailableBytes uint64 `json:"availableBytes,omitempty"` + GoMemoryBytes uint64 `json:"goMemoryBytes,omitempty"` + GoHeapLiveBytes uint64 `json:"goHeapLiveBytes,omitempty"` + GoStackBytes uint64 `json:"goStackBytes,omitempty"` + Goroutines uint64 `json:"goroutines,omitempty"` + GCCycles uint64 `json:"gcCycles,omitempty"` + Connections int `json:"connections,omitempty"` +} + +type eventRecord struct { + Type string `json:"t"` + At string `json:"at"` + Policy string `json:"policy,omitempty"` + State string `json:"state,omitempty"` + Reason string `json:"reason,omitempty"` + MemoryBytes uint64 `json:"memoryBytes,omitempty"` + AvailableBytes uint64 `json:"availableBytes,omitempty"` + MemoryAfterBytes uint64 `json:"memoryAfterBytes,omitempty"` + MemoryLimit uint64 `json:"memoryLimit,omitempty"` + TriggerBytes uint64 `json:"triggerBytes,omitempty"` + ArmedBytes uint64 `json:"armedBytes,omitempty"` + ResumeBytes uint64 `json:"resumeBytes,omitempty"` + ReportOnly bool `json:"reportOnly,omitempty"` + Connections int `json:"connections,omitempty"` + Sequence int `json:"seq,omitempty"` + Prefix string `json:"prefix,omitempty"` + Runtime *runtimeStats `json:"runtime,omitempty"` +} + +type runtimeStats struct { + HeapAlloc uint64 `json:"heapAlloc"` + HeapObjects uint64 `json:"heapObjects"` + HeapInuse uint64 `json:"heapInuse"` + HeapIdle uint64 `json:"heapIdle"` + HeapReleased uint64 `json:"heapReleased"` + HeapSys uint64 `json:"heapSys"` + StackInuse uint64 `json:"stackInuse"` + StackSys uint64 `json:"stackSys"` + Sys uint64 `json:"sys"` + TotalAlloc uint64 `json:"totalAlloc"` + NumGC uint32 `json:"numGC"` + NumGoroutine int `json:"numGoroutine"` + NextGC uint64 `json:"nextGC"` + LastGC string `json:"lastGC,omitempty"` +} + +func NewRecorder(options RecorderOptions) *Recorder { + recorderLogger := options.Logger + if recorderLogger == nil { + recorderLogger = logger.NOP() + } + return &Recorder{ + basePath: options.BasePath, + draftPath: filepath.Join(options.BasePath, DraftDirectoryName), + logger: recorderLogger, + acceptDraft: options.AcceptDraft, + metadataCallback: options.MetadataCallback, + ownerCallback: options.OwnerCallback, + logCallback: options.LogCallback, + snapshotCallback: options.SnapshotCallback, + metricsSamples: []metrics.Sample{ + {Name: "/memory/classes/total:bytes"}, + {Name: "/gc/heap/live:bytes"}, + {Name: "/memory/classes/heap/stacks:bytes"}, + {Name: "/sched/goroutines:goroutines"}, + {Name: "/gc/cycles/total:gc-cycles"}, + }, + lastSnapshotAt: make(map[string]time.Time), + } +} + +func (r *Recorder) Start() { + r.access.Lock() + defer r.access.Unlock() + if r.started { + return + } + PromoteDraft(r.basePath, r.acceptDraft) + r.started = true + r.status.StartedAt = time.Now() +} + +func (r *Recorder) Close() error { + r.snapshotAccess.Lock() + defer r.snapshotAccess.Unlock() + r.access.Lock() + defer r.access.Unlock() + if !r.started || r.closed { + return nil + } + r.closed = true + if !r.draftCreated { + return nil + } + if !r.notable { + r.releaseDraftLocked() + return os.RemoveAll(r.draftPath) + } + r.status.EndedAt = time.Now() + r.writeLogLocked() + r.writeMetadataLocked() + r.releaseDraftLocked() + promoteDirectory(r.draftPath, filepath.Join(r.basePath, ReportsDirectoryName)) + return nil +} + +func (r *Recorder) releaseDraftLocked() { + if r.draftLock == nil { + return + } + os.Remove(r.draftLock.Name()) + unlockDraft(r.draftLock) + r.draftLock = nil +} + +func (r *Recorder) WriteReport() error { + sample := memorySample{usage: memory.Total()} + if memory.AvailableAvailable() { + sample.availableKnown = true + sample.available = memory.Available() + } + err := r.snapshot(SnapshotReasonManual, sample, true) + if err != nil { + return E.Cause(err, "write snapshot") + } + r.access.Lock() + defer r.access.Unlock() + reportsDir := filepath.Join(r.basePath, ReportsDirectoryName) + err = os.MkdirAll(reportsDir, 0o777) + if err != nil { + return E.Cause(err, "create reports directory") + } + r.chown(reportsDir) + destPath, err := nextAvailableReportPath(reportsDir, time.Now().UTC()) + if err != nil { + return err + } + r.appendEventLocked(eventRecord{Type: eventTypeReport, MemoryBytes: sample.usage, AvailableBytes: sample.available}) + err = copyDirectory(r.draftPath, destPath) + if err != nil { + os.RemoveAll(destPath) + return E.Cause(err, "copy draft to ", destPath) + } + r.chownTree(destPath) + return nil +} + +func (r *Recorder) instanceStarted(config timerConfig, thresholds pressureThresholds) { + r.access.Lock() + defer r.access.Unlock() + r.status.MemoryLimit = config.memoryLimit + r.appendEventLocked(eventRecord{ + Type: eventTypeStart, + Policy: config.policyMode.String(), + MemoryLimit: config.memoryLimit, + TriggerBytes: thresholds.trigger, + ArmedBytes: thresholds.armed, + ResumeBytes: thresholds.resume, + ReportOnly: config.killerDisabled, + }) +} + +func (r *Recorder) instanceStopped() { + r.access.Lock() + defer r.access.Unlock() + r.appendEventLocked(eventRecord{Type: eventTypeStop}) +} + +func (r *Recorder) sample(sample memorySample, state pressureState, connections int) { + now := time.Now() + r.access.Lock() + defer r.access.Unlock() + if r.closed { + return + } + r.observeLocked(sample) + if r.hasRow && state == r.lastRowState { + interval := normalSampleInterval + if now.Before(r.denseUntil) { + interval = pressureSampleInterval + } + if now.Sub(r.lastRowAt) < interval { + return + } + } + err := r.ensureDraftLocked() + if err != nil { + return + } + metrics.Read(r.metricsSamples) + gcCycles := r.metricsSamples[4].Value.Uint64() + row := timelineRow{ + At: now.UTC().Format(time.RFC3339), + State: state.String(), + MemoryBytes: sample.usage, + AvailableBytes: sample.available, + GoMemoryBytes: r.metricsSamples[0].Value.Uint64(), + GoHeapLiveBytes: r.metricsSamples[1].Value.Uint64(), + GoStackBytes: r.metricsSamples[2].Value.Uint64(), + Goroutines: r.metricsSamples[3].Value.Uint64(), + Connections: connections, + } + if r.hasRow { + row.GCCycles = gcCycles - r.previousGCCycles + } + r.previousGCCycles = gcCycles + r.hasRow = true + r.lastRowAt = now + r.lastRowState = state + timelinePath := filepath.Join(r.draftPath, timelineFileName) + err = appendRecord(timelinePath, row) + if err != nil { + r.logger.Error(E.Cause(err, "OOM report: write timeline")) + return + } + r.chown(timelinePath) +} + +func (r *Recorder) recordPressure(sample memorySample) { + r.access.Lock() + defer r.access.Unlock() + r.notable = true + r.observeLocked(sample) + r.denseUntil = time.Now().Add(denseSampleWindow) + r.appendEventLocked(eventRecord{Type: eventTypePressure, MemoryBytes: sample.usage, AvailableBytes: sample.available}) +} + +func (r *Recorder) recordStateChange(state pressureState, sample memorySample) { + r.access.Lock() + defer r.access.Unlock() + r.observeLocked(sample) + r.denseUntil = time.Now().Add(denseSampleWindow) + r.appendEventLocked(eventRecord{Type: eventTypeState, State: state.String(), MemoryBytes: sample.usage, AvailableBytes: sample.available}) +} + +func (r *Recorder) recordReset(reason string, before memorySample, after memorySample, connections int, reportOnly bool) { + r.access.Lock() + defer r.access.Unlock() + r.notable = true + r.observeLocked(before) + r.denseUntil = time.Now().Add(denseSampleWindow) + r.appendEventLocked(eventRecord{ + Type: eventTypeReset, + Reason: reason, + MemoryBytes: before.usage, + AvailableBytes: before.available, + MemoryAfterBytes: after.usage, + Connections: connections, + ReportOnly: reportOnly, + }) +} + +func (r *Recorder) snapshot(reason string, sample memorySample, force bool) error { + r.snapshotAccess.Lock() + defer r.snapshotAccess.Unlock() + now := time.Now() + if !force { + if r.automaticSnapshots >= maxAutomaticSnapshots { + return nil + } + var minInterval time.Duration + switch reason { + case SnapshotReasonPressure: + minInterval = pressureSnapshotMinInterval + case SnapshotReasonReset: + minInterval = resetSnapshotMinInterval + } + lastAt, found := r.lastSnapshotAt[reason] + if found && now.Sub(lastAt) < minInterval { + return nil + } + } + r.access.Lock() + if r.closed { + r.access.Unlock() + return E.New("OOM recorder closed") + } + err := r.ensureDraftLocked() + r.access.Unlock() + if err != nil { + return err + } + r.snapshotSequence++ + sequence := r.snapshotSequence + if !force { + r.automaticSnapshots++ + } + r.lastSnapshotAt[reason] = now + prefix := "snapshot-" + strconv.Itoa(sequence) + "-" + reason + if r.snapshotCallback != nil { + r.snapshotCallback(r.draftPath, prefix) + } + var memStats runtime.MemStats + runtime.ReadMemStats(&memStats) + stats := &runtimeStats{ + HeapAlloc: memStats.HeapAlloc, + HeapObjects: memStats.HeapObjects, + HeapInuse: memStats.HeapInuse, + HeapIdle: memStats.HeapIdle, + HeapReleased: memStats.HeapReleased, + HeapSys: memStats.HeapSys, + StackInuse: memStats.StackInuse, + StackSys: memStats.StackSys, + Sys: memStats.Sys, + TotalAlloc: memStats.TotalAlloc, + NumGC: memStats.NumGC, + NumGoroutine: runtime.NumGoroutine(), + NextGC: memStats.NextGC, + } + if memStats.LastGC > 0 { + stats.LastGC = time.Unix(0, int64(memStats.LastGC)).UTC().Format(time.RFC3339) + } + r.access.Lock() + defer r.access.Unlock() + r.notable = true + r.status.Snapshots = sequence + r.observeLocked(sample) + r.writeLogLocked() + r.appendEventLocked(eventRecord{ + Type: eventTypeSnapshot, + Reason: reason, + Sequence: sequence, + Prefix: prefix, + MemoryBytes: sample.usage, + AvailableBytes: sample.available, + Runtime: stats, + }) + return nil +} + +func (r *Recorder) observeLocked(sample memorySample) { + if sample.usage > r.status.PeakMemory { + r.status.PeakMemory = sample.usage + } + if sample.availableKnown && (!r.status.AvailableKnown || sample.available < r.status.MinAvailable) { + r.status.AvailableKnown = true + r.status.MinAvailable = sample.available + } +} + +func (r *Recorder) ensureDraftLocked() error { + if r.draftCreated { + _, err := os.Stat(r.draftPath) + if err == nil { + return nil + } + r.logger.Error("OOM report: draft directory lost, recreating") + r.releaseDraftLocked() + r.draftCreated = false + r.hasRow = false + } + if !r.started { + return E.New("OOM recorder not started") + } + if r.closed { + return E.New("OOM recorder closed") + } + err := os.MkdirAll(r.draftPath, 0o777) + if err != nil { + r.logger.Error(E.Cause(err, "OOM report: create draft directory")) + return E.Cause(err, "create draft directory ", r.draftPath) + } + r.chown(r.draftPath) + lockPath := filepath.Join(r.draftPath, lockFileName) + r.draftLock, err = lockDraft(lockPath) + if err != nil { + return E.Cause(err, "lock draft directory ", r.draftPath) + } + r.chown(lockPath) + r.draftCreated = true + r.writeMetadataLocked() + return nil +} + +func (r *Recorder) appendEventLocked(event eventRecord) { + if r.closed { + return + } + err := r.ensureDraftLocked() + if err != nil { + return + } + event.At = time.Now().UTC().Format(time.RFC3339) + eventsPath := filepath.Join(r.draftPath, eventsFileName) + err = appendRecord(eventsPath, event) + if err != nil { + r.logger.Error(E.Cause(err, "OOM report: write events")) + } else { + r.chown(eventsPath) + } + r.writeMetadataLocked() +} + +func (r *Recorder) writeMetadataLocked() { + if r.metadataCallback == nil { + return + } + r.status.RecordedAt = time.Now() + content, err := json.Marshal(r.metadataCallback(r.status)) + if err != nil { + return + } + r.writeFile(filepath.Join(r.draftPath, metadataFileName), content) +} + +func (r *Recorder) writeLogLocked() { + if r.logCallback == nil { + return + } + content := r.logCallback() + if len(content) == 0 { + return + } + r.writeFile(filepath.Join(r.draftPath, logFileName), content) +} + +func (r *Recorder) writeFile(path string, content []byte) { + err := os.WriteFile(path, content, 0o666) + if err != nil { + r.logger.Error(E.Cause(err, "OOM report: write ", filepath.Base(path))) + return + } + r.chown(path) +} + +func (r *Recorder) chown(path string) { + if r.ownerCallback != nil { + r.ownerCallback(path) + } +} + +func (r *Recorder) chownTree(directory string) { + r.chown(directory) + entries, err := os.ReadDir(directory) + if err != nil { + return + } + for _, entry := range entries { + r.chown(filepath.Join(directory, entry.Name())) + } +} + +func appendRecord(path string, record any) error { + file, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o666) + if err != nil { + return err + } + defer file.Close() + return json.NewEncoder(file).Encode(record) +} diff --git a/service/oomkiller/service.go b/service/oomkiller/service.go index d2bef722..7ce51616 100644 --- a/service/oomkiller/service.go +++ b/service/oomkiller/service.go @@ -2,39 +2,29 @@ package oomkiller import ( "context" - "sync/atomic" - "time" "github.com/sagernet/sing-box/adapter" boxService "github.com/sagernet/sing-box/adapter/service" boxConstant "github.com/sagernet/sing-box/constant" "github.com/sagernet/sing-box/log" "github.com/sagernet/sing-box/option" + E "github.com/sagernet/sing/common/exceptions" "github.com/sagernet/sing/service" ) -type OOMReporter interface { - WriteReport(memoryUsage uint64) error - WriteDraft(memoryUsage uint64) error - DiscardDraft() error -} - func RegisterService(registry *boxService.Registry) { boxService.Register[option.OOMKillerServiceOptions](registry, boxConstant.TypeOOMKiller, NewService) } type Service struct { boxService.Adapter - ctx context.Context - logger log.ContextLogger - network adapter.NetworkManager - timerConfig timerConfig - adaptiveTimer *adaptiveTimer - lastReportTime atomic.Int64 - //nolint:unused // touched only on darwin && cgo via writeOOMDraft/discardOOMDraft. - lastDraftTime atomic.Int64 - //nolint:unused // touched only on darwin && cgo via writeOOMDraft/discardOOMDraft. - draftCancelled atomic.Bool + ctx context.Context + logger log.ContextLogger + network adapter.NetworkManager + connections adapter.ConnectionManager + recorder *Recorder + timerConfig timerConfig + adaptiveTimer *adaptiveTimer } func NewService(ctx context.Context, logger log.ContextLogger, tag string, options option.OOMKillerServiceOptions) (adapter.Service, error) { @@ -48,27 +38,29 @@ func NewService(ctx context.Context, logger log.ContextLogger, tag string, optio ctx: ctx, logger: logger, network: service.FromContext[adapter.NetworkManager](ctx), + connections: service.FromContext[adapter.ConnectionManager](ctx), + recorder: service.FromContext[*Recorder](ctx), timerConfig: config, }, nil } -func (s *Service) writeOOMReport(memoryUsage uint64) { - now := time.Now().Unix() - lastReport := s.lastReportTime.Load() - if now-lastReport < 3600 { - return +func (s *Service) startTimer() error { + if !s.timerConfig.policyMode.hasTimerMode() { + return E.New("memory pressure monitoring is not available on this platform without memory_limit") } - if !s.lastReportTime.CompareAndSwap(lastReport, now) { - return + s.adaptiveTimer = newAdaptiveTimer(s.logger, s.network, s.connections, s.recorder, s.timerConfig) + if s.recorder != nil { + s.recorder.instanceStarted(s.timerConfig, s.adaptiveTimer.limitThresholds) } - reporter := service.FromContext[OOMReporter](s.ctx) - if reporter == nil { - return + s.adaptiveTimer.start() + return nil +} + +func (s *Service) stopTimer() { + if s.adaptiveTimer != nil { + s.adaptiveTimer.stop() } - err := reporter.WriteReport(memoryUsage) - if err != nil { - s.logger.Warn("failed to write OOM report: ", err) - } else { - s.logger.Info("OOM report saved") + if s.recorder != nil { + s.recorder.instanceStopped() } } diff --git a/service/oomkiller/service_darwin.go b/service/oomkiller/service_darwin.go index 166ddc7d..a3814cde 100644 --- a/service/oomkiller/service_darwin.go +++ b/service/oomkiller/service_darwin.go @@ -34,16 +34,11 @@ import "C" import ( "sync" - "time" "github.com/sagernet/sing-box/adapter" "github.com/sagernet/sing/common/byteformats" - E "github.com/sagernet/sing/common/exceptions" - "github.com/sagernet/sing/service" ) -const oomDraftMinInterval = time.Hour - var ( globalAccess sync.Mutex globalServices []*Service @@ -53,8 +48,11 @@ func (s *Service) Start(stage adapter.StartStage) error { if stage != adapter.StartStateStart { return nil } + err := s.startTimer() + if err != nil { + return err + } if s.timerConfig.policyMode == policyModeNetworkExtension { - s.adaptiveTimer = newAdaptiveTimer(s.logger, s.network, s.timerConfig, nil) globalAccess.Lock() isFirst := len(globalServices) == 0 globalServices = append(globalServices, s) @@ -62,20 +60,12 @@ func (s *Service) Start(stage adapter.StartStage) error { if isFirst { C.startMemoryPressureMonitor() } - return nil } - if !s.timerConfig.policyMode.hasTimerMode() { - return E.New("memory pressure monitoring is not available on this platform without memory_limit") - } - s.adaptiveTimer = newAdaptiveTimer(s.logger, s.network, s.timerConfig, s.writeOOMReport) - s.adaptiveTimer.start() return nil } func (s *Service) Close() error { - if s.adaptiveTimer != nil { - s.adaptiveTimer.stop() - } + s.stopTimer() if s.timerConfig.policyMode == policyModeNetworkExtension { globalAccess.Lock() for i, svc := range globalServices { @@ -89,7 +79,6 @@ func (s *Service) Close() error { if isLast { C.stopMemoryPressureMonitor() } - s.discardOOMDraft() } return nil } @@ -106,45 +95,12 @@ func goMemoryPressureCallback(status C.ulong) { sample := readMemorySample(policyModeNetworkExtension) for _, s := range services { s.logger.Warn("memory pressure: critical, usage: ", byteformats.FormatMemoryBytes(sample.usage)) - s.writeOOMDraft(sample.usage) + if s.recorder != nil { + s.recorder.recordPressure(sample) + } s.adaptiveTimer.notifyPressure() - } -} - -func (s *Service) writeOOMDraft(memoryUsage uint64) { - if s.draftCancelled.Load() { - return - } - now := time.Now().UnixNano() - lastDraft := s.lastDraftTime.Load() - if time.Duration(now-lastDraft) < oomDraftMinInterval { - return - } - s.lastDraftTime.Store(now) - reporter := service.FromContext[OOMReporter](s.ctx) - if reporter == nil { - return - } - err := reporter.WriteDraft(memoryUsage) - if s.draftCancelled.Load() { - reporter.DiscardDraft() - return - } - if err != nil { - s.logger.Error("failed to write OOM draft: ", err) - } else { - s.logger.Warn("OOM draft saved") - } -} - -func (s *Service) discardOOMDraft() { - s.draftCancelled.Store(true) - reporter := service.FromContext[OOMReporter](s.ctx) - if reporter == nil { - return - } - err := reporter.DiscardDraft() - if err != nil { - s.logger.Error("failed to discard OOM draft: ", err) + if s.recorder != nil { + s.recorder.snapshot(SnapshotReasonPressure, sample, false) + } } } diff --git a/service/oomkiller/service_stub.go b/service/oomkiller/service_stub.go index 81ebbf03..f75fe8d5 100644 --- a/service/oomkiller/service_stub.go +++ b/service/oomkiller/service_stub.go @@ -4,24 +4,16 @@ package oomkiller import ( "github.com/sagernet/sing-box/adapter" - E "github.com/sagernet/sing/common/exceptions" ) func (s *Service) Start(stage adapter.StartStage) error { if stage != adapter.StartStateStart { return nil } - if !s.timerConfig.policyMode.hasTimerMode() { - return E.New("memory pressure monitoring is not available on this platform without memory_limit") - } - s.adaptiveTimer = newAdaptiveTimer(s.logger, s.network, s.timerConfig, s.writeOOMReport) - s.adaptiveTimer.start() - return nil + return s.startTimer() } func (s *Service) Close() error { - if s.adaptiveTimer != nil { - s.adaptiveTimer.stop() - } + s.stopTimer() return nil } diff --git a/service/oomkiller/timer.go b/service/oomkiller/timer.go index 1f38956f..5dfdd7b3 100644 --- a/service/oomkiller/timer.go +++ b/service/oomkiller/timer.go @@ -102,7 +102,8 @@ type adaptiveTimer struct { timerConfig logger log.ContextLogger network adapter.NetworkManager - onTriggered func(uint64) + connections adapter.ConnectionManager + recorder *Recorder limitThresholds pressureThresholds access sync.Mutex @@ -115,12 +116,13 @@ type adaptiveTimer struct { pressureBaselineTime time.Time } -func newAdaptiveTimer(logger log.ContextLogger, network adapter.NetworkManager, config timerConfig, onTriggered func(uint64)) *adaptiveTimer { +func newAdaptiveTimer(logger log.ContextLogger, network adapter.NetworkManager, connections adapter.ConnectionManager, recorder *Recorder, config timerConfig) *adaptiveTimer { t := &adaptiveTimer{ timerConfig: config, logger: logger, network: network, - onTriggered: onTriggered, + connections: connections, + recorder: recorder, } if config.policyMode == policyModeMemoryLimit || config.policyMode == policyModeNetworkExtension { t.limitThresholds = computeLimitThresholds(config.memoryLimit, config.safetyMargin) @@ -192,14 +194,24 @@ func (t *adaptiveTimer) poll() { } } } + state := t.state t.access.Unlock() + var connections int + if t.connections != nil { + connections = t.connections.Count() + } + if t.recorder != nil { + t.recorder.sample(sample, state, connections) + if state != previousState { + t.recorder.recordStateChange(state, sample) + } + } if !triggered { return } - if t.onTriggered != nil { - t.onTriggered(sample.usage) - } + var reason string if rateTriggered { + reason = resetReasonRate if t.killerDisabled { t.logger.Warn("memory growth rate critical (report only), usage: ", byteformats.FormatMemoryBytes(sample.usage), t.logDetails(sample)) } else { @@ -207,6 +219,7 @@ func (t *adaptiveTimer) poll() { t.network.ResetNetwork(context.Background()) } } else { + reason = resetReasonThreshold if t.killerDisabled { t.logger.Warn("memory threshold reached (report only), usage: ", byteformats.FormatMemoryBytes(sample.usage), t.logDetails(sample)) } else { @@ -216,6 +229,10 @@ func (t *adaptiveTimer) poll() { } badCleanup() runtimeDebug.FreeOSMemory() + if t.recorder != nil { + t.recorder.recordReset(reason, sample, readMemorySample(t.policyMode), connections, t.killerDisabled) + t.recorder.snapshot(SnapshotReasonReset, sample, false) + } } func (t *adaptiveTimer) nextState(sample memorySample) pressureState { @@ -320,9 +337,20 @@ func readMemorySample(mode policyMode) memorySample { sample := memorySample{ usage: memory.Total(), } - if mode == policyModeAvailable { + if mode == policyModeAvailable || mode == policyModeNetworkExtension { sample.availableKnown = true sample.available = memory.Available() } return sample } + +func (s pressureState) String() string { + switch s { + case pressureStateArmed: + return "armed" + case pressureStateTriggered: + return "triggered" + default: + return "normal" + } +} diff --git a/service/oomkiller/timer_darwin.go b/service/oomkiller/timer_darwin.go index f73ab28f..7cb1993e 100644 --- a/service/oomkiller/timer_darwin.go +++ b/service/oomkiller/timer_darwin.go @@ -5,6 +5,7 @@ package oomkiller import runtimeDebug "runtime/debug" func (t *adaptiveTimer) notifyPressure() { + badCleanup() runtimeDebug.FreeOSMemory() t.access.Lock() t.startLocked()