From 43fd8f237062b2db233611bc45240f94cd4ea4c8 Mon Sep 17 00:00:00 2001 From: Marc Frei Date: Fri, 29 Mar 2024 12:27:18 +0100 Subject: [PATCH] Work on transition to slog --- benchmark/client.go | 11 +++++++++++ benchmark/client_ip.go | 22 ++++++++++++++-------- benchmark/client_scion.go | 39 +++++++++++++++++++++++++-------------- timeservice.go | 17 ++++++++++------- 4 files changed, 60 insertions(+), 29 deletions(-) diff --git a/benchmark/client.go b/benchmark/client.go index 6a4e1b3e..f234be87 100644 --- a/benchmark/client.go +++ b/benchmark/client.go @@ -1,5 +1,16 @@ package benchmark +import ( + "context" + "log/slog" + "os" +) + +func logFatal(ctx context.Context, log *slog.Logger, msg string, attrs ...slog.Attr) { + log.LogAttrs(ctx, slog.LevelError, msg, attrs...) + os.Exit(1) +} + func contains(s []string, v string) bool { for _, x := range s { if x == v { diff --git a/benchmark/client_ip.go b/benchmark/client_ip.go index 84f5a9c7..3f455983 100644 --- a/benchmark/client_ip.go +++ b/benchmark/client_ip.go @@ -3,22 +3,26 @@ package benchmark import ( "context" "crypto/tls" + "log/slog" "net" "os" "sync" "time" "github.com/HdrHistogram/hdrhistogram-go" - "go.uber.org/zap" + "example.com/scion-time/base/zaplog" "example.com/scion-time/core/client" ) -func RunIPBenchmark(localAddr, remoteAddr *net.UDPAddr, authModes []string, ntskeServer string, log *zap.Logger) { +func RunIPBenchmark(localAddr, remoteAddr *net.UDPAddr, authModes []string, ntskeServer string, log *slog.Logger) { // const numClientGoroutine = 8 // const numRequestPerClient = 10000 const numClientGoroutine = 1 const numRequestPerClient = 20_000 + + ctx := context.Background() + var mu sync.Mutex sg := make(chan struct{}) var wg sync.WaitGroup @@ -28,7 +32,6 @@ func RunIPBenchmark(localAddr, remoteAddr *net.UDPAddr, authModes []string, ntsk go func() { var err error hg := hdrhistogram.New(1, 50000, 5) - ctx := context.Background() c := &client.IPClient{ InterleavedMode: true, @@ -38,7 +41,7 @@ func RunIPBenchmark(localAddr, remoteAddr *net.UDPAddr, authModes []string, ntsk if contains(authModes, "nts") { ntskeHost, ntskePort, err := net.SplitHostPort(ntskeServer) if err != nil { - log.Fatal("failed to split NTS-KE host and port", zap.Error(err)) + logFatal(ctx, log, "failed to split NTS-KE host and port", slog.Any("error", err)) } c.Auth.Enabled = true c.Auth.NTSKEFetcher.TLSConfig = tls.Config{ @@ -47,15 +50,18 @@ func RunIPBenchmark(localAddr, remoteAddr *net.UDPAddr, authModes []string, ntsk MinVersion: tls.VersionTLS13, } c.Auth.NTSKEFetcher.Port = ntskePort - c.Auth.NTSKEFetcher.Log = log + c.Auth.NTSKEFetcher.Log = zaplog.Logger() } defer wg.Done() <-sg for range numRequestPerClient { - _, _, err = client.MeasureClockOffsetIP(ctx, log, c, localAddr, remoteAddr) + _, _, err = client.MeasureClockOffsetIP(ctx, zaplog.Logger(), c, localAddr, remoteAddr) if err != nil { - log.Info("failed to measure clock offset", zap.Error(err)) + log.LogAttrs(ctx, slog.LevelInfo, + "failed to measure clock offset", + slog.Any("error", err), + ) } } mu.Lock() @@ -66,5 +72,5 @@ func RunIPBenchmark(localAddr, remoteAddr *net.UDPAddr, authModes []string, ntsk t0 := time.Now() close(sg) wg.Wait() - log.Info(time.Since(t0).String()) + log.LogAttrs(ctx, slog.LevelInfo, "time elbasped", slog.Duration("duration", time.Since(t0))) } diff --git a/benchmark/client_scion.go b/benchmark/client_scion.go index 8003057d..3731515f 100644 --- a/benchmark/client_scion.go +++ b/benchmark/client_scion.go @@ -3,28 +3,35 @@ package benchmark import ( "context" "crypto/tls" + "log/slog" "net" "os" "sync" "time" "github.com/HdrHistogram/hdrhistogram-go" - "go.uber.org/zap" "github.com/scionproto/scion/pkg/daemon" "github.com/scionproto/scion/pkg/snet" "github.com/scionproto/scion/pkg/snet/path" + "example.com/scion-time/base/zaplog" "example.com/scion-time/core/client" "example.com/scion-time/net/scion" "example.com/scion-time/net/udp" ) -func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, authModes []string, ntskeServer string, log *zap.Logger) { +func RunSCIONBenchmark( + daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, + authModes []string, ntskeServer string, + log *slog.Logger) { // const numClientGoroutine = 8 // const numRequestPerClient = 10000 const numClientGoroutine = 1 const numRequestPerClient = 20_000 + + ctx := context.Background() + var mu sync.Mutex sg := make(chan struct{}) var wg sync.WaitGroup @@ -34,7 +41,6 @@ func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, a go func() { var err error hg := hdrhistogram.New(1, 50000, 5) - ctx := context.Background() dc := scion.NewDaemonConnector(ctx, daemonAddr) @@ -48,13 +54,17 @@ func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, a } else { ps, err = dc.Paths(ctx, remoteAddr.IA, localAddr.IA, daemon.PathReqFlags{Refresh: true}) if err != nil { - log.Fatal("failed to lookup paths", zap.Stringer("to", remoteAddr.IA), zap.Error(err)) + logFatal(ctx, log, "failed to lookup paths", slog.Any("to", remoteAddr.IA), slog.Any("error", err)) } if len(ps) == 0 { - log.Fatal("no paths available", zap.Stringer("to", remoteAddr.IA)) + logFatal(ctx, log, "no paths available", slog.Any("to", remoteAddr.IA)) } } - log.Debug("available paths", zap.Stringer("to", remoteAddr.IA), zap.Array("via", scion.PathArrayMarshaler{Paths: ps})) + log.LogAttrs(ctx, slog.LevelDebug, + "available paths", + slog.Any("to", remoteAddr.IA), + slog.Any("via", ps), + ) laddr := udp.UDPAddrFromSnet(localAddr) raddr := udp.UDPAddrFromSnet(remoteAddr) @@ -71,7 +81,7 @@ func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, a if contains(authModes, "nts") { ntskeHost, ntskePort, err := net.SplitHostPort(ntskeServer) if err != nil { - log.Fatal("failed to split NTS-KE host and port", zap.Error(err)) + logFatal(ctx, log, "failed to split NTS-KE host and port", slog.Any("error", err)) } c.Auth.NTSEnabled = true c.Auth.NTSKEFetcher.TLSConfig = tls.Config{ @@ -80,7 +90,7 @@ func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, a MinVersion: tls.VersionTLS13, } c.Auth.NTSKEFetcher.Port = ntskePort - c.Auth.NTSKEFetcher.Log = log + c.Auth.NTSKEFetcher.Log = zaplog.Logger() c.Auth.NTSKEFetcher.QUIC.Enabled = true c.Auth.NTSKEFetcher.QUIC.DaemonAddr = daemonAddr c.Auth.NTSKEFetcher.QUIC.LocalAddr = laddr @@ -91,12 +101,13 @@ func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, a <-sg ntpcs := []*client.SCIONClient{c} for range numRequestPerClient { - _, _, err = client.MeasureClockOffsetSCION(ctx, log, ntpcs, laddr, raddr, ps) + _, _, err = client.MeasureClockOffsetSCION(ctx, zaplog.Logger(), ntpcs, laddr, raddr, ps) if err != nil { - log.Info("failed to measure clock offset", - zap.Stringer("remoteIA", raddr.IA), - zap.Stringer("remoteHost", raddr.Host), - zap.Error(err), + log.LogAttrs(ctx, slog.LevelInfo, + "failed to measure clock offset", + slog.Any("remoteIA", raddr.IA), + slog.Any("remoteHost", raddr.Host), + slog.Any("error", err), ) } } @@ -108,5 +119,5 @@ func RunSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, a t0 := time.Now() close(sg) wg.Wait() - log.Info(time.Since(t0).String()) + log.LogAttrs(ctx, slog.LevelInfo, "time elbasped", slog.Duration("duration", time.Since(t0))) } diff --git a/timeservice.go b/timeservice.go index 968fff16..fe7d4454 100644 --- a/timeservice.go +++ b/timeservice.go @@ -615,9 +615,10 @@ func runSCIONTool(daemonAddr, dispatcherMode string, localAddr, remoteAddr *snet logFatal("no paths available", slog.Any("to", remoteAddr.IA)) } } - zaplog.Logger().Debug("available paths", - zap.Stringer("to", remoteAddr.IA), - zap.Array("via", scion.PathArrayMarshaler{Paths: ps}), + log.LogAttrs(ctx, slog.LevelDebug, + "available paths", + slog.Any("to", remoteAddr.IA), + slog.Any("via", ps), ) laddr := udp.UDPAddrFromSnet(localAddr) @@ -646,6 +647,8 @@ func runSCIONTool(daemonAddr, dispatcherMode string, localAddr, remoteAddr *snet func runBenchmark(configFile string) { cfg := loadConfig(configFile) + log := slog.Default() + localAddr := localAddress(cfg) daemonAddr := daemonAddress(cfg) remoteAddr := remoteAddress(cfg) @@ -654,22 +657,22 @@ func runBenchmark(configFile string) { ntskeServer := ntskeServerFromRemoteAddr(cfg.RemoteAddr) if !remoteAddr.IA.IsZero() { - runSCIONBenchmark(daemonAddr, localAddr, remoteAddr, cfg.AuthModes, ntskeServer, zaplog.Logger()) + runSCIONBenchmark(daemonAddr, localAddr, remoteAddr, cfg.AuthModes, ntskeServer, log) } else { if daemonAddr != "" { exitWithUsage() } - runIPBenchmark(localAddr, remoteAddr, cfg.AuthModes, ntskeServer, zaplog.Logger()) + runIPBenchmark(localAddr, remoteAddr, cfg.AuthModes, ntskeServer, log) } } -func runIPBenchmark(localAddr, remoteAddr *snet.UDPAddr, authModes []string, ntskeServer string, log *zap.Logger) { +func runIPBenchmark(localAddr, remoteAddr *snet.UDPAddr, authModes []string, ntskeServer string, log *slog.Logger) { lclk := &clock.SystemClock{Log: slog.New(logbase.NewNopHandler())} timebase.RegisterClock(lclk) benchmark.RunIPBenchmark(localAddr.Host, remoteAddr.Host, authModes, ntskeServer, log) } -func runSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, authModes []string, ntskeServer string, log *zap.Logger) { +func runSCIONBenchmark(daemonAddr string, localAddr, remoteAddr *snet.UDPAddr, authModes []string, ntskeServer string, log *slog.Logger) { lclk := &clock.SystemClock{Log: slog.New(logbase.NewNopHandler())} timebase.RegisterClock(lclk) benchmark.RunSCIONBenchmark(daemonAddr, localAddr, remoteAddr, authModes, ntskeServer, log)