Update sing-box core

adapter/connections.go

@@ -9,6 +9,10 @@ import (
 
 type ConnectionManager interface {
 	Lifecycle
+	Count() int
+	CloseAll()
+	TrackConn(conn net.Conn) net.Conn
+	TrackPacketConn(conn net.PacketConn) net.PacketConn
 	NewConnection(ctx context.Context, this N.Dialer, conn net.Conn, metadata InboundContext, onClose N.CloseHandlerFunc)
 	NewPacketConnection(ctx context.Context, this N.Dialer, conn N.PacketConn, metadata InboundContext, onClose N.CloseHandlerFunc)
 }

adapter/dns.go

@@ -68,6 +68,7 @@ type DNSTransport interface {
 	Type() string
 	Tag() string
 	Dependencies() []string
+	Reset()
 	Exchange(ctx context.Context, message *dns.Msg) (*dns.Msg, error)
 }
 

adapter/endpoint/manager.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"os"
 	"sync"
+	"time"
 
 	"github.com/sagernet/sing-box/adapter"
 	"github.com/sagernet/sing-box/common/taskmonitor"
@@ -11,6 +12,7 @@ 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)
@@ -48,10 +50,14 @@ func (m *Manager) Start(stage adapter.StartStage) error {
 	endpoints := m.endpoints
 	m.access.Unlock()
 	for _, endpoint := range endpoints {
+		name := "endpoint/" + endpoint.Type() + "[" + endpoint.Tag() + "]"
+		m.logger.Trace(stage, " ", name)
+		startTime := time.Now()
 		err := adapter.LegacyStart(endpoint, stage)
 		if err != nil {
-			return E.Cause(err, stage, " endpoint/", endpoint.Type(), "[", endpoint.Tag(), "]")
+			return E.Cause(err, stage, " ", name)
 		}
+		m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
@@ -68,11 +74,15 @@ func (m *Manager) Close() error {
 	monitor := taskmonitor.New(m.logger, C.StopTimeout)
 	var err error
 	for _, endpoint := range endpoints {
-		monitor.Start("close endpoint/", endpoint.Type(), "[", endpoint.Tag(), "]")
+		name := "endpoint/" + endpoint.Type() + "[" + endpoint.Tag() + "]"
+		m.logger.Trace("close ", name)
+		startTime := time.Now()
+		monitor.Start("close ", name)
 		err = E.Append(err, endpoint.Close(), func(err error) error {
-			return E.Cause(err, "close endpoint/", endpoint.Type(), "[", endpoint.Tag(), "]")
+			return E.Cause(err, "close ", name)
 		})
 		monitor.Finish()
+		m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
@@ -121,11 +131,15 @@ func (m *Manager) Create(ctx context.Context, router adapter.Router, logger log.
 	m.access.Lock()
 	defer m.access.Unlock()
 	if m.started {
+		name := "endpoint/" + endpoint.Type() + "[" + endpoint.Tag() + "]"
 		for _, stage := range adapter.ListStartStages {
+			m.logger.Trace(stage, " ", name)
+			startTime := time.Now()
 			err = adapter.LegacyStart(endpoint, stage)
 			if err != nil {
-				return E.Cause(err, stage, " endpoint/", endpoint.Type(), "[", endpoint.Tag(), "]")
+				return E.Cause(err, stage, " ", name)
 			}
+			m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 		}
 	}
 	if existsEndpoint, loaded := m.endpointByTag[tag]; loaded {

adapter/experimental.go

@@ -4,8 +4,10 @@ import (
 	"bytes"
 	"context"
 	"encoding/binary"
+	"io"
 	"time"
 
+	"github.com/sagernet/sing/common/observable"
 	"github.com/sagernet/sing/common/varbin"
 )
 
@@ -14,6 +16,7 @@ type ClashServer interface {
 	ConnectionTracker
 	Mode() string
 	ModeList() []string
+	SetModeUpdateHook(hook *observable.Subscriber[struct{}])
 	HistoryStorage() URLTestHistoryStorage
 }
 
@@ -23,7 +26,7 @@ type URLTestHistory struct {
 }
 
 type URLTestHistoryStorage interface {
-	SetHook(hook chan<- struct{})
+	SetHook(hook *observable.Subscriber[struct{}])
 	LoadURLTestHistory(tag string) *URLTestHistory
 	DeleteURLTestHistory(tag string)
 	StoreURLTestHistory(tag string, history *URLTestHistory)
@@ -70,7 +73,11 @@ func (s *SavedBinary) MarshalBinary() ([]byte, error) {
 	if err != nil {
 		return nil, err
 	}
-	err = varbin.Write(&buffer, binary.BigEndian, s.Content)
+	_, err = varbin.WriteUvarint(&buffer, uint64(len(s.Content)))
+	if err != nil {
+		return nil, err
+	}
+	_, err = buffer.Write(s.Content)
 	if err != nil {
 		return nil, err
 	}
@@ -78,7 +85,11 @@ func (s *SavedBinary) MarshalBinary() ([]byte, error) {
 	if err != nil {
 		return nil, err
 	}
-	err = varbin.Write(&buffer, binary.BigEndian, s.LastEtag)
+	_, err = varbin.WriteUvarint(&buffer, uint64(len(s.LastEtag)))
+	if err != nil {
+		return nil, err
+	}
+	_, err = buffer.WriteString(s.LastEtag)
 	if err != nil {
 		return nil, err
 	}
@@ -92,7 +103,12 @@ func (s *SavedBinary) UnmarshalBinary(data []byte) error {
 	if err != nil {
 		return err
 	}
-	err = varbin.Read(reader, binary.BigEndian, &s.Content)
+	contentLength, err := binary.ReadUvarint(reader)
+	if err != nil {
+		return err
+	}
+	s.Content = make([]byte, contentLength)
+	_, err = io.ReadFull(reader, s.Content)
 	if err != nil {
 		return err
 	}
@@ -102,10 +118,16 @@ func (s *SavedBinary) UnmarshalBinary(data []byte) error {
 		return err
 	}
 	s.LastUpdated = time.Unix(lastUpdated, 0)
-	err = varbin.Read(reader, binary.BigEndian, &s.LastEtag)
+	etagLength, err := binary.ReadUvarint(reader)
 	if err != nil {
 		return err
 	}
+	etagBytes := make([]byte, etagLength)
+	_, err = io.ReadFull(reader, etagBytes)
+	if err != nil {
+		return err
+	}
+	s.LastEtag = string(etagBytes)
 	return nil
 }
 

adapter/inbound.go

@@ -5,7 +5,6 @@ import (
 	"net/netip"
 	"time"
 
-	"github.com/sagernet/sing-box/common/process"
 	C "github.com/sagernet/sing-box/constant"
 	"github.com/sagernet/sing-box/log"
 	"github.com/sagernet/sing-box/option"
@@ -66,13 +65,10 @@ type InboundContext struct {
 	// cache
 
 	// Deprecated: implement in rule action
-	InboundDetour            string
-	LastInbound              string
-	OriginDestination        M.Socksaddr
-	RouteOriginalDestination M.Socksaddr
-	// Deprecated: to be removed
-	//nolint:staticcheck
-	InboundOptions            option.InboundOptions
+	InboundDetour             string
+	LastInbound               string
+	OriginDestination         M.Socksaddr
+	RouteOriginalDestination  M.Socksaddr
 	UDPDisableDomainUnmapping bool
 	UDPConnect                bool
 	UDPTimeout                time.Duration
@@ -88,7 +84,7 @@ type InboundContext struct {
 	DestinationAddresses []netip.Addr
 	SourceGeoIPCode      string
 	GeoIPCode            string
-	ProcessInfo          *process.Info
+	ProcessInfo          *ConnectionOwner
 	QueryType            uint16
 	FakeIP               bool
 

adapter/inbound/manager.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"os"
 	"sync"
+	"time"
 
 	"github.com/sagernet/sing-box/adapter"
 	"github.com/sagernet/sing-box/common/taskmonitor"
@@ -11,6 +12,7 @@ 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)
@@ -45,10 +47,14 @@ func (m *Manager) Start(stage adapter.StartStage) error {
 	inbounds := m.inbounds
 	m.access.Unlock()
 	for _, inbound := range inbounds {
+		name := "inbound/" + inbound.Type() + "[" + inbound.Tag() + "]"
+		m.logger.Trace(stage, " ", name)
+		startTime := time.Now()
 		err := adapter.LegacyStart(inbound, stage)
 		if err != nil {
-			return E.Cause(err, stage, " inbound/", inbound.Type(), "[", inbound.Tag(), "]")
+			return E.Cause(err, stage, " ", name)
 		}
+		m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
@@ -65,11 +71,15 @@ func (m *Manager) Close() error {
 	monitor := taskmonitor.New(m.logger, C.StopTimeout)
 	var err error
 	for _, inbound := range inbounds {
-		monitor.Start("close inbound/", inbound.Type(), "[", inbound.Tag(), "]")
+		name := "inbound/" + inbound.Type() + "[" + inbound.Tag() + "]"
+		m.logger.Trace("close ", name)
+		startTime := time.Now()
+		monitor.Start("close ", name)
 		err = E.Append(err, inbound.Close(), func(err error) error {
-			return E.Cause(err, "close inbound/", inbound.Type(), "[", inbound.Tag(), "]")
+			return E.Cause(err, "close ", name)
 		})
 		monitor.Finish()
+		m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
@@ -121,11 +131,15 @@ func (m *Manager) Create(ctx context.Context, router adapter.Router, logger log.
 	m.access.Lock()
 	defer m.access.Unlock()
 	if m.started {
+		name := "inbound/" + inbound.Type() + "[" + inbound.Tag() + "]"
 		for _, stage := range adapter.ListStartStages {
+			m.logger.Trace(stage, " ", name)
+			startTime := time.Now()
 			err = adapter.LegacyStart(inbound, stage)
 			if err != nil {
-				return E.Cause(err, stage, " inbound/", inbound.Type(), "[", inbound.Tag(), "]")
+				return E.Cause(err, stage, " ", name)
 			}
+			m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 		}
 	}
 	if existsInbound, loaded := m.inboundByTag[tag]; loaded {

adapter/lifecycle.go

@@ -1,6 +1,14 @@
 package adapter
 
-import E "github.com/sagernet/sing/common/exceptions"
+import (
+	"reflect"
+	"strings"
+	"time"
+
+	"github.com/sagernet/sing-box/log"
+	E "github.com/sagernet/sing/common/exceptions"
+	F "github.com/sagernet/sing/common/format"
+)
 
 type SimpleLifecycle interface {
 	Start() error
@@ -48,22 +56,47 @@ type LifecycleService interface {
 	Lifecycle
 }
 
-func Start(stage StartStage, services ...Lifecycle) error {
+func getServiceName(service any) string {
+	if named, ok := service.(interface {
+		Type() string
+		Tag() string
+	}); ok {
+		tag := named.Tag()
+		if tag != "" {
+			return named.Type() + "[" + tag + "]"
+		}
+		return named.Type()
+	}
+	t := reflect.TypeOf(service)
+	if t.Kind() == reflect.Ptr {
+		t = t.Elem()
+	}
+	return strings.ToLower(t.Name())
+}
+
+func Start(logger log.ContextLogger, stage StartStage, services ...Lifecycle) error {
 	for _, service := range services {
+		name := getServiceName(service)
+		logger.Trace(stage, " ", name)
+		startTime := time.Now()
 		err := service.Start(stage)
 		if err != nil {
 			return err
 		}
+		logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
 
-func StartNamed(stage StartStage, services []LifecycleService) error {
+func StartNamed(logger log.ContextLogger, stage StartStage, services []LifecycleService) error {
 	for _, service := range services {
+		logger.Trace(stage, " ", service.Name())
+		startTime := time.Now()
 		err := service.Start(stage)
 		if err != nil {
 			return E.Cause(err, stage.String(), " ", service.Name())
 		}
+		logger.Trace(stage, " ", service.Name(), " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }

adapter/network.go

@@ -10,6 +10,7 @@ import (
 
 type NetworkManager interface {
 	Lifecycle
+	Initialize(ruleSets []RuleSet)
 	InterfaceFinder() control.InterfaceFinder
 	UpdateInterfaces() error
 	DefaultNetworkInterface() *NetworkInterface
@@ -24,9 +25,10 @@ type NetworkManager interface {
 	NetworkMonitor() tun.NetworkUpdateMonitor
 	InterfaceMonitor() tun.DefaultInterfaceMonitor
 	PackageManager() tun.PackageManager
+	NeedWIFIState() bool
 	WIFIState() WIFIState
-	ResetNetwork()
 	UpdateWIFIState()
+	ResetNetwork()
 }
 
 type NetworkOptions struct {

adapter/outbound.go

@@ -2,9 +2,12 @@ package adapter
 
 import (
 	"context"
+	"net/netip"
+	"time"
 
 	"github.com/sagernet/sing-box/log"
 	"github.com/sagernet/sing-box/option"
+	"github.com/sagernet/sing-tun"
 	N "github.com/sagernet/sing/common/network"
 )
 
@@ -18,6 +21,17 @@ type Outbound interface {
 	N.Dialer
 }
 
+type OutboundWithPreferredRoutes interface {
+	Outbound
+	PreferredDomain(domain string) bool
+	PreferredAddress(address netip.Addr) bool
+}
+
+type DirectRouteOutbound interface {
+	Outbound
+	NewDirectRouteConnection(metadata InboundContext, routeContext tun.DirectRouteContext, timeout time.Duration) (tun.DirectRouteDestination, error)
+}
+
 type OutboundRegistry interface {
 	option.OutboundOptionsRegistry
 	CreateOutbound(ctx context.Context, router Router, logger log.ContextLogger, tag string, outboundType string, options any) (Outbound, error)

adapter/outbound/manager.go

@@ -6,6 +6,7 @@ import (
 	"os"
 	"strings"
 	"sync"
+	"time"
 
 	"github.com/sagernet/sing-box/adapter"
 	"github.com/sagernet/sing-box/common/taskmonitor"
@@ -13,6 +14,7 @@ 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"
 )
 
@@ -81,10 +83,14 @@ func (m *Manager) Start(stage adapter.StartStage) error {
 		outbounds := m.outbounds
 		m.access.Unlock()
 		for _, outbound := range outbounds {
+			name := "outbound/" + outbound.Type() + "[" + outbound.Tag() + "]"
+			m.logger.Trace(stage, " ", name)
+			startTime := time.Now()
 			err := adapter.LegacyStart(outbound, stage)
 			if err != nil {
-				return E.Cause(err, stage, " outbound/", outbound.Type(), "[", outbound.Tag(), "]")
+				return E.Cause(err, stage, " ", name)
 			}
+			m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 		}
 	}
 	return nil
@@ -109,22 +115,29 @@ func (m *Manager) startOutbounds(outbounds []adapter.Outbound) error {
 			}
 			started[outboundTag] = true
 			canContinue = true
+			name := "outbound/" + outboundToStart.Type() + "[" + outboundTag + "]"
 			if starter, isStarter := outboundToStart.(adapter.Lifecycle); isStarter {
-				monitor.Start("start outbound/", outboundToStart.Type(), "[", outboundTag, "]")
+				m.logger.Trace("start ", name)
+				startTime := time.Now()
+				monitor.Start("start ", name)
 				err := starter.Start(adapter.StartStateStart)
 				monitor.Finish()
 				if err != nil {
-					return E.Cause(err, "start outbound/", outboundToStart.Type(), "[", outboundTag, "]")
+					return E.Cause(err, "start ", name)
 				}
+				m.logger.Trace("start ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 			} else if starter, isStarter := outboundToStart.(interface {
 				Start() error
 			}); isStarter {
-				monitor.Start("start outbound/", outboundToStart.Type(), "[", outboundTag, "]")
+				m.logger.Trace("start ", name)
+				startTime := time.Now()
+				monitor.Start("start ", name)
 				err := starter.Start()
 				monitor.Finish()
 				if err != nil {
-					return E.Cause(err, "start outbound/", outboundToStart.Type(), "[", outboundTag, "]")
+					return E.Cause(err, "start ", name)
 				}
+				m.logger.Trace("start ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 			}
 		}
 		if len(started) == len(outbounds) {
@@ -171,11 +184,15 @@ func (m *Manager) Close() error {
 	var err error
 	for _, outbound := range outbounds {
 		if closer, isCloser := outbound.(io.Closer); isCloser {
-			monitor.Start("close outbound/", outbound.Type(), "[", outbound.Tag(), "]")
+			name := "outbound/" + outbound.Type() + "[" + outbound.Tag() + "]"
+			m.logger.Trace("close ", name)
+			startTime := time.Now()
+			monitor.Start("close ", name)
 			err = E.Append(err, closer.Close(), func(err error) error {
-				return E.Cause(err, "close outbound/", outbound.Type(), "[", outbound.Tag(), "]")
+				return E.Cause(err, "close ", name)
 			})
 			monitor.Finish()
+			m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 		}
 	}
 	return nil
@@ -256,11 +273,15 @@ func (m *Manager) Create(ctx context.Context, router adapter.Router, logger log.
 		return err
 	}
 	if m.started {
+		name := "outbound/" + outbound.Type() + "[" + outbound.Tag() + "]"
 		for _, stage := range adapter.ListStartStages {
+			m.logger.Trace(stage, " ", name)
+			startTime := time.Now()
 			err = adapter.LegacyStart(outbound, stage)
 			if err != nil {
-				return E.Cause(err, stage, " outbound/", outbound.Type(), "[", outbound.Tag(), "]")
+				return E.Cause(err, stage, " ", name)
 			}
+			m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 		}
 	}
 	m.access.Lock()

adapter/platform.go

@@ -0,0 +1,70 @@
+package adapter
+
+import (
+	"github.com/sagernet/sing-box/option"
+	"github.com/sagernet/sing-tun"
+	"github.com/sagernet/sing/common/logger"
+)
+
+type PlatformInterface interface {
+	Initialize(networkManager NetworkManager) error
+
+	UsePlatformAutoDetectInterfaceControl() bool
+	AutoDetectInterfaceControl(fd int) error
+
+	UsePlatformInterface() bool
+	OpenInterface(options *tun.Options, platformOptions option.TunPlatformOptions) (tun.Tun, error)
+
+	UsePlatformDefaultInterfaceMonitor() bool
+	CreateDefaultInterfaceMonitor(logger logger.Logger) tun.DefaultInterfaceMonitor
+
+	UsePlatformNetworkInterfaces() bool
+	NetworkInterfaces() ([]NetworkInterface, error)
+
+	UnderNetworkExtension() bool
+	NetworkExtensionIncludeAllNetworks() bool
+
+	ClearDNSCache()
+	RequestPermissionForWIFIState() error
+	ReadWIFIState() WIFIState
+	SystemCertificates() []string
+
+	UsePlatformConnectionOwnerFinder() bool
+	FindConnectionOwner(request *FindConnectionOwnerRequest) (*ConnectionOwner, error)
+
+	UsePlatformWIFIMonitor() bool
+
+	UsePlatformNotification() bool
+	SendNotification(notification *Notification) error
+}
+
+type FindConnectionOwnerRequest struct {
+	IpProtocol         int32
+	SourceAddress      string
+	SourcePort         int32
+	DestinationAddress string
+	DestinationPort    int32
+}
+
+type ConnectionOwner struct {
+	ProcessID          uint32
+	UserId             int32
+	UserName           string
+	ProcessPath        string
+	AndroidPackageName string
+}
+
+type Notification struct {
+	Identifier string
+	TypeName   string
+	TypeID     int32
+	Title      string
+	Subtitle   string
+	Body       string
+	OpenURL    string
+}
+
+type SystemProxyStatus struct {
+	Available bool
+	Enabled   bool
+}

adapter/router.go

@@ -6,8 +6,10 @@ import (
 	"net"
 	"net/http"
 	"sync"
+	"time"
 
 	C "github.com/sagernet/sing-box/constant"
+	"github.com/sagernet/sing-tun"
 	M "github.com/sagernet/sing/common/metadata"
 	N "github.com/sagernet/sing/common/network"
 	"github.com/sagernet/sing/common/ntp"
@@ -19,11 +21,11 @@ import (
 type Router interface {
 	Lifecycle
 	ConnectionRouter
-	PreMatch(metadata InboundContext) error
+	PreMatch(metadata InboundContext, context tun.DirectRouteContext, timeout time.Duration, supportBypass bool) (tun.DirectRouteDestination, error)
 	ConnectionRouterEx
 	RuleSet(tag string) (RuleSet, bool)
-	NeedWIFIState() bool
 	Rules() []Rule
+	NeedFindProcess() bool
 	AppendTracker(tracker ConnectionTracker)
 	ResetNetwork()
 }

adapter/service/manager.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"os"
 	"sync"
+	"time"
 
 	"github.com/sagernet/sing-box/adapter"
 	"github.com/sagernet/sing-box/common/taskmonitor"
@@ -11,6 +12,7 @@ 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)
@@ -43,10 +45,14 @@ func (m *Manager) Start(stage adapter.StartStage) error {
 	services := m.services
 	m.access.Unlock()
 	for _, service := range services {
+		name := "service/" + service.Type() + "[" + service.Tag() + "]"
+		m.logger.Trace(stage, " ", name)
+		startTime := time.Now()
 		err := adapter.LegacyStart(service, stage)
 		if err != nil {
-			return E.Cause(err, stage, " service/", service.Type(), "[", service.Tag(), "]")
+			return E.Cause(err, stage, " ", name)
 		}
+		m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
@@ -63,11 +69,15 @@ func (m *Manager) Close() error {
 	monitor := taskmonitor.New(m.logger, C.StopTimeout)
 	var err error
 	for _, service := range services {
-		monitor.Start("close service/", service.Type(), "[", service.Tag(), "]")
+		name := "service/" + service.Type() + "[" + service.Tag() + "]"
+		m.logger.Trace("close ", name)
+		startTime := time.Now()
+		monitor.Start("close ", name)
 		err = E.Append(err, service.Close(), func(err error) error {
-			return E.Cause(err, "close service/", service.Type(), "[", service.Tag(), "]")
+			return E.Cause(err, "close ", name)
 		})
 		monitor.Finish()
+		m.logger.Trace("close ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 	}
 	return nil
 }
@@ -116,11 +126,15 @@ func (m *Manager) Create(ctx context.Context, logger log.ContextLogger, tag stri
 	m.access.Lock()
 	defer m.access.Unlock()
 	if m.started {
+		name := "service/" + service.Type() + "[" + service.Tag() + "]"
 		for _, stage := range adapter.ListStartStages {
+			m.logger.Trace(stage, " ", name)
+			startTime := time.Now()
 			err = adapter.LegacyStart(service, stage)
 			if err != nil {
-				return E.Cause(err, stage, " service/", service.Type(), "[", service.Tag(), "]")
+				return E.Cause(err, stage, " ", name)
 			}
+			m.logger.Trace(stage, " ", name, " completed (", F.Seconds(time.Since(startTime).Seconds()), "s)")
 		}
 	}
 	if existsService, loaded := m.serviceByTag[tag]; loaded {