diff --git a/adapter/endpoint/manager.go b/adapter/endpoint/manager.go index 8b7c287f..7d7aa4bc 100644 --- a/adapter/endpoint/manager.go +++ b/adapter/endpoint/manager.go @@ -12,7 +12,6 @@ import ( "github.com/sagernet/sing-box/log" "github.com/sagernet/sing/common" E "github.com/sagernet/sing/common/exceptions" - F "github.com/sagernet/sing/common/format" ) var _ adapter.EndpointManager = (*Manager)(nil) @@ -55,7 +54,7 @@ func (m *Manager) Start(stage adapter.StartStage) error { if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } return nil } @@ -80,7 +79,7 @@ func (m *Manager) Close() error { return E.Cause(err, "close ", name) }) monitor.Finish() - m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, "close ", name) } return nil } @@ -137,7 +136,7 @@ func (m *Manager) Create(ctx context.Context, router adapter.Router, logger log. if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } } if existsEndpoint, loaded := m.endpointByTag[tag]; loaded { diff --git a/adapter/inbound/manager.go b/adapter/inbound/manager.go index 438c20f4..2d1b0d2e 100644 --- a/adapter/inbound/manager.go +++ b/adapter/inbound/manager.go @@ -12,7 +12,6 @@ import ( "github.com/sagernet/sing-box/log" "github.com/sagernet/sing/common" E "github.com/sagernet/sing/common/exceptions" - F "github.com/sagernet/sing/common/format" ) var _ adapter.InboundManager = (*Manager)(nil) @@ -54,7 +53,7 @@ func (m *Manager) Start(stage adapter.StartStage) error { if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } return nil } @@ -79,7 +78,7 @@ func (m *Manager) Close() error { return E.Cause(err, "close ", name) }) monitor.Finish() - m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, "close ", name) } return nil } @@ -139,7 +138,7 @@ func (m *Manager) Create(ctx context.Context, router adapter.Router, logger log. if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } } if existsInbound, loaded := m.inboundByTag[tag]; loaded { diff --git a/adapter/lifecycle.go b/adapter/lifecycle.go index b969c98a..ebc0a303 100644 --- a/adapter/lifecycle.go +++ b/adapter/lifecycle.go @@ -83,7 +83,7 @@ func Start(logger log.ContextLogger, stage StartStage, services ...Lifecycle) er if err != nil { return err } - logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + LogElapsed(logger, startTime, stage, " ", name) } return nil } @@ -96,7 +96,14 @@ func StartNamed(logger log.ContextLogger, stage StartStage, services []Lifecycle if err != nil { return E.Cause(err, stage.String(), " ", service.Name()) } - logger.Trace(stage, " ", service.Name(), " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + LogElapsed(logger, startTime, stage, " ", service.Name()) } return nil } + +func LogElapsed(logger log.ContextLogger, startTime time.Time, description ...any) { + duration := time.Since(startTime) + if duration > time.Second { + logger.Trace(append(description, " completed (", F.Seconds(duration.Seconds()), "s)")...) + } +} diff --git a/adapter/outbound/manager.go b/adapter/outbound/manager.go index 5c1b5d99..287f1a91 100644 --- a/adapter/outbound/manager.go +++ b/adapter/outbound/manager.go @@ -14,7 +14,6 @@ import ( "github.com/sagernet/sing-box/log" "github.com/sagernet/sing/common" E "github.com/sagernet/sing/common/exceptions" - F "github.com/sagernet/sing/common/format" "github.com/sagernet/sing/common/logger" ) @@ -90,7 +89,7 @@ func (m *Manager) Start(stage adapter.StartStage) error { if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } } return nil @@ -125,7 +124,7 @@ func (m *Manager) startOutbounds(outbounds []adapter.Outbound) error { if err != nil { return E.Cause(err, "start ", name) } - m.logger.Trace("start ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, "start ", name) } else if starter, isStarter := outboundToStart.(interface { Start() error }); isStarter { @@ -137,7 +136,7 @@ func (m *Manager) startOutbounds(outbounds []adapter.Outbound) error { if err != nil { return E.Cause(err, "start ", name) } - m.logger.Trace("start ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, "start ", name) } } if len(started) == len(outbounds) { @@ -192,7 +191,7 @@ func (m *Manager) Close() error { return E.Cause(err, "close ", name) }) monitor.Finish() - m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, "close ", name) } } return nil @@ -281,7 +280,7 @@ func (m *Manager) Create(ctx context.Context, router adapter.Router, logger log. if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } } m.access.Lock() diff --git a/adapter/service/manager.go b/adapter/service/manager.go index f17aa07e..8ae961de 100644 --- a/adapter/service/manager.go +++ b/adapter/service/manager.go @@ -12,7 +12,6 @@ import ( "github.com/sagernet/sing-box/log" "github.com/sagernet/sing/common" E "github.com/sagernet/sing/common/exceptions" - F "github.com/sagernet/sing/common/format" ) var _ adapter.ServiceManager = (*Manager)(nil) @@ -52,7 +51,7 @@ func (m *Manager) Start(stage adapter.StartStage) error { if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } return nil } @@ -77,7 +76,7 @@ func (m *Manager) Close() error { return E.Cause(err, "close ", name) }) monitor.Finish() - m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, "close ", name) } return nil } @@ -134,7 +133,7 @@ func (m *Manager) Create(ctx context.Context, logger log.ContextLogger, tag stri if err != nil { return E.Cause(err, stage, " ", name) } - m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(m.logger, startTime, stage, " ", name) } } if existsService, loaded := m.serviceByTag[tag]; loaded { diff --git a/box.go b/box.go index a72884e0..549f2fe0 100644 --- a/box.go +++ b/box.go @@ -520,7 +520,7 @@ func (s *Box) Close() error { err = E.Append(err, closeItem.service.Close(), func(err error) error { return E.Cause(err, "close ", closeItem.name) }) - s.logger.Trace("close ", closeItem.name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(s.logger, startTime, "close ", closeItem.name) } for _, lifecycleService := range s.internalService { s.logger.Trace("close ", lifecycleService.Name()) @@ -528,14 +528,14 @@ func (s *Box) Close() error { err = E.Append(err, lifecycleService.Close(), func(err error) error { return E.Cause(err, "close ", lifecycleService.Name()) }) - s.logger.Trace("close ", lifecycleService.Name(), " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(s.logger, startTime, "close ", lifecycleService.Name()) } s.logger.Trace("close logger") startTime := time.Now() err = E.Append(err, s.logFactory.Close(), func(err error) error { return E.Cause(err, "close logger") }) - s.logger.Trace("close logger completed (", F.Seconds(time.Since(startTime).Seconds()), "s)") + adapter.LogElapsed(s.logger, startTime, "close logger") return err }