diff --git a/go.mod b/go.mod index e924ae97..71105c60 100644 --- a/go.mod +++ b/go.mod @@ -10,11 +10,13 @@ require ( github.com/docker/docker v28.0.1+incompatible github.com/dustinkirkland/golang-petname v0.0.0-20240428194347-eebcea082ee0 github.com/ethereum/go-ethereum v1.15.10 + github.com/fatih/color v1.18.0 github.com/flashbots/go-boost-utils v1.9.1-0.20250819134059-e5294cb450c9 github.com/flashbots/mev-boost-relay v0.32.0-rc2 github.com/hashicorp/go-uuid v1.0.3 github.com/holiman/uint256 v1.3.2 github.com/otiai10/copy v1.14.1 + github.com/phsym/console-slog v0.3.1 github.com/sirupsen/logrus v1.9.3 github.com/spf13/cobra v1.9.1 github.com/spf13/pflag v1.0.6 @@ -90,6 +92,7 @@ require ( github.com/klauspost/cpuid/v2 v2.2.10 // indirect github.com/lib/pq v1.10.9 // indirect github.com/lucasb-eyer/go-colorful v1.2.0 // indirect + github.com/mattn/go-colorable v0.1.14 // indirect github.com/mattn/go-isatty v0.0.20 // indirect github.com/mattn/go-localereader v0.0.1 // indirect github.com/mattn/go-runewidth v0.0.16 // indirect @@ -156,7 +159,7 @@ require ( golang.org/x/crypto v0.37.0 // indirect golang.org/x/net v0.38.0 // indirect golang.org/x/oauth2 v0.26.0 // indirect - golang.org/x/sys v0.32.0 // indirect + golang.org/x/sys v0.33.0 // indirect golang.org/x/term v0.31.0 // indirect golang.org/x/text v0.24.0 // indirect golang.org/x/time v0.9.0 // indirect diff --git a/go.sum b/go.sum index 9b8477a7..522f73f0 100644 --- a/go.sum +++ b/go.sum @@ -126,6 +126,8 @@ github.com/ethereum/go-ethereum v1.15.10 h1:UxqBhpsF2TNF1f7Z/k3RUUHEuLvDGAlHuh/l github.com/ethereum/go-ethereum v1.15.10/go.mod h1:+S9k+jFzlyVTNcYGvqFhzN/SFhI6vA+aOY4T5tLSPL0= github.com/ethereum/go-verkle v0.2.2 h1:I2W0WjnrFUIzzVPwm8ykY+7pL2d4VhlsePn4j7cnFk8= github.com/ethereum/go-verkle v0.2.2/go.mod h1:M3b90YRnzqKyyzBEWJGqj8Qff4IDeXnzFw0P9bFw3uk= +github.com/fatih/color v1.18.0 h1:S8gINlzdQ840/4pfAwic/ZE0djQEH3wM94VfqLTZcOM= +github.com/fatih/color v1.18.0/go.mod h1:4FelSpRwEGDpQ12mAdzqdOukCy4u8WUtOY6lkT/6HfU= github.com/felixge/httpsnoop v1.0.4 h1:NFTV2Zj1bL4mc9sqWACXbQFVBBg2W3GPvqp8/ESS2Wg= github.com/felixge/httpsnoop v1.0.4/go.mod h1:m8KPJKqk1gH5J9DgRY2ASl2lWCfGKXixSwevea8zH2U= github.com/ferranbt/fastssz v0.0.0-20210120143747-11b9eff30ea9/go.mod h1:DyEu2iuLBnb/T51BlsiO3yLYdJC6UbGMrIkqK1KmQxM= @@ -351,6 +353,8 @@ github.com/patrickmn/go-cache v2.1.0+incompatible h1:HRMgzkcYKYpi3C8ajMPV8OFXaaR github.com/patrickmn/go-cache v2.1.0+incompatible/go.mod h1:3Qf8kWWT7OJRJbdiICTKqZju1ZixQ/KpMGzzAfe6+WQ= github.com/peterh/liner v1.2.0 h1:w/UPXyl5GfahFxcTOz2j9wCIHNI+pUPr2laqpojKNCg= github.com/peterh/liner v1.2.0/go.mod h1:CRroGNssyjTd/qIG2FyxByd2S8JEAZXBl4qUrZf8GS0= +github.com/phsym/console-slog v0.3.1 h1:Fuzcrjr40xTc004S9Kni8XfNsk+qrptQmyR+wZw9/7A= +github.com/phsym/console-slog v0.3.1/go.mod h1:oJskjp/X6e6c0mGpfP8ELkfKUsrkDifYRAqJQgmdDS0= github.com/pion/dtls/v2 v2.2.12 h1:KP7H5/c1EiVAAKUmXyCzPiQe5+bCJrpOeKg/L05dunk= github.com/pion/dtls/v2 v2.2.12/go.mod h1:d9SYc9fch0CqK90mRk1dC7AkzzpwJj6u2GU3u+9pqFE= github.com/pion/logging v0.2.2 h1:M9+AIj/+pxNsDfAT64+MAVgJO0rsyLnoJKCqf//DoeY= @@ -538,8 +542,8 @@ golang.org/x/sys v0.0.0-20220908164124-27713097b956/go.mod h1:oPkhp1MJrh7nUepCBc golang.org/x/sys v0.1.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.14.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= -golang.org/x/sys v0.32.0 h1:s77OFDvIQeibCmezSnk/q6iAfkdiQaJi4VzroCFrN20= -golang.org/x/sys v0.32.0/go.mod h1:BJP2sWEmIv4KK5OTEluFJCKSidICx8ciO85XgH3Ak8k= +golang.org/x/sys v0.33.0 h1:q3i8TbbEz+JRD9ywIRlyRAQbM0qF7hu24q3teo2hbuw= +golang.org/x/sys v0.33.0/go.mod h1:BJP2sWEmIv4KK5OTEluFJCKSidICx8ciO85XgH3Ak8k= golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8= diff --git a/main.go b/main.go index 75d561bc..aebd5e52 100644 --- a/main.go +++ b/main.go @@ -5,19 +5,24 @@ import ( _ "embed" "fmt" "log" + "log/slog" "os" "sort" "strings" "time" + "github.com/fatih/color" "github.com/flashbots/builder-playground/playground" "github.com/flashbots/builder-playground/utils" + "github.com/flashbots/builder-playground/utils/logging" "github.com/flashbots/builder-playground/utils/mainctx" "github.com/spf13/cobra" ) var version = "dev" +var greenColor = color.New(color.FgGreen) + var ( keepFlag bool outputFlag string @@ -315,17 +320,17 @@ func main() { } func runIt(recipe playground.Recipe) error { + fmt.Println() + var logLevel playground.LogLevel if err := logLevel.Unmarshal(logLevelFlag); err != nil { return fmt.Errorf("failed to parse log level: %w", err) } - - if logLevel == playground.LevelTrace { - // TODO: We can remove this once we have a logger with log.Trace support - utils.TraceMode = true - } - - log.Printf("Log level: %s\n", logLevel) + logging.ConfigureSlog(logLevelFlag) + sessionID := utils.GeneratePetName() + slog.Info("Welcome to Builder Playground! ⚡️🤖") + slog.Info("Session ID: "+greenColor.Sprint(sessionID), "log-level", logLevel) + slog.Info("") // parse the overrides overrides := map[string]string{} @@ -342,7 +347,7 @@ func runIt(recipe playground.Recipe) error { return err } - log.Println("Building artifacts...") + slog.Debug("Building artifacts...") builder := recipe.Artifacts() builder.GenesisDelay(genesisDelayFlag) builder.PrefundedAccounts(prefundedAccounts) @@ -360,12 +365,12 @@ func runIt(recipe playground.Recipe) error { }, } - svcManager := playground.NewManifest(exCtx, out) + svcManager := playground.NewManifest(exCtx, out, sessionID) recipe.Apply(svcManager) // generate the dot graph - log.Println("Generating dot graph...") + slog.Debug("Generating dot graph...") dotGraph := svcManager.GenerateDotGraph() if err := out.WriteFile("graph.dot", dotGraph); err != nil { return err @@ -410,11 +415,9 @@ func runIt(recipe playground.Recipe) error { } // Add callback to log service updates in debug mode - if logLevel == playground.LevelDebug { - cfg.AddCallback(func(serviceName string, update playground.TaskStatus) { - log.Printf("[DEBUG] [%s] %s\n", serviceName, update) - }) - } + cfg.AddCallback(func(serviceName string, update playground.TaskStatus) { + slog.Debug("service update", "service", serviceName, "status", update) + }) dockerRunner, err := playground.NewLocalRunner(cfg) if err != nil { @@ -423,34 +426,36 @@ func runIt(recipe playground.Recipe) error { ctx := mainctx.Get() - log.Println("Starting services...") + slog.Info("Starting services... ⏳", "session-id", svcManager.ID) if err := dockerRunner.Run(ctx); err != nil { dockerRunner.Stop(keepFlag) return fmt.Errorf("failed to run docker: %w", err) } if !interactive { + log.Println() + log.Println("All services started! ✅") // print services info - fmt.Printf("\n========= Services started =========\n") for _, ss := range svcManager.Services { ports := ss.GetPorts() sort.Slice(ports, func(i, j int) bool { return ports[i].Name < ports[j].Name }) - portsStr := []string{} + var portsStr []any for _, p := range ports { protocol := "" if p.Protocol == playground.ProtocolUDP { protocol = "/udp" } - portsStr = append(portsStr, fmt.Sprintf("%s: %d/%d%s", p.Name, p.Port, p.HostPort, protocol)) + portsStr = append(portsStr, p.Name, fmt.Sprintf("%d/%d%s", p.Port, p.HostPort, protocol)) } - fmt.Printf("- %s (%s)\n", ss.Name, strings.Join(portsStr, ", ")) + slog.Info("• "+ss.Name, portsStr...) } + log.Println() } - fmt.Println("\nWaiting for services to get healthy...") + log.Println("Waiting for services to get healthy... ⏳") waitCtx, cancel := context.WithTimeout(ctx, time.Minute) defer cancel() if err := dockerRunner.WaitForReady(waitCtx); err != nil { @@ -458,15 +463,16 @@ func runIt(recipe playground.Recipe) error { return fmt.Errorf("failed to wait for service readiness: %w", err) } - fmt.Println("\nAll services are healthy! Ready to accept transactions.") - fmt.Println("Session ID:", svcManager.ID) + slog.Info("All services are healthy! Ready to accept transactions. 🚀", "session-id", svcManager.ID) // get the output from the recipe output := recipe.Output(svcManager) if len(output) > 0 { - fmt.Printf("\n========= Output =========\n") + slog.Info("") + slog.Info("Recipe outputs 🔍") for k, v := range output { - fmt.Printf("- %s: %v\n", k, v) + valStr := fmt.Sprintf("%v", v) + slog.Info("• " + k + ": " + greenColor.Sprint(valStr)) } } @@ -492,13 +498,13 @@ func runIt(recipe playground.Recipe) error { select { case <-ctx.Done(): - fmt.Println("Stopping...") + log.Println("Stopping...") case err := <-dockerRunner.ExitErr(): - fmt.Println("Service failed:", err) + log.Println("Service failed:", err) case err := <-watchdogErr: - fmt.Println("Watchdog failed:", err) + log.Println("Watchdog failed:", err) case <-timerCh: - fmt.Println("Timeout reached") + log.Println("Timeout reached") } if err := dockerRunner.Stop(keepFlag); err != nil { diff --git a/playground/artifacts.go b/playground/artifacts.go index 6105587a..238cc285 100644 --- a/playground/artifacts.go +++ b/playground/artifacts.go @@ -12,6 +12,7 @@ import ( "fmt" "io" "log" + "log/slog" "maps" "math/big" "os" @@ -176,7 +177,7 @@ func (b *ArtifactsBuilder) Build(out *output) error { } block := gen.ToBlock() - log.Printf("Genesis block hash: %s", block.Hash()) + slog.Info("Genesis block created", "hash", block.Hash()) var v int if b.applyLatestL1Fork { @@ -185,7 +186,7 @@ func (b *ArtifactsBuilder) Build(out *output) error { v = version.Deneb } - log.Println("Generating keys...") + slog.Debug("Generating keys...") keys, err := keys.GetPregeneratedBLSKeys() if err != nil { return err @@ -213,7 +214,7 @@ func (b *ArtifactsBuilder) Build(out *output) error { return err } - log.Println("Writing artifacts...") + slog.Debug("Writing artifacts...") err = out.WriteBatch(map[string]interface{}{ "testnet/config.yaml": func() ([]byte, error) { return convert(config) }, "testnet/genesis.ssz": state, @@ -228,7 +229,7 @@ func (b *ArtifactsBuilder) Build(out *output) error { if err != nil { return err } - log.Println("Done writing artifacts.") + slog.Debug("Done writing artifacts.") { // We have to start slightly ahead of L1 genesis time diff --git a/playground/manifest.go b/playground/manifest.go index fcad0fea..d0a29437 100644 --- a/playground/manifest.go +++ b/playground/manifest.go @@ -72,10 +72,13 @@ func (m *Manifest) ApplyOverrides(overrides map[string]string) error { return nil } -func NewManifest(ctx *ExContext, out *output) *Manifest { +func NewManifest(ctx *ExContext, out *output, name ...string) *Manifest { + if len(name) == 0 { + name = []string{utils.GeneratePetName()} + } ctx.Output = out return &Manifest{ - ID: utils.GeneratePetName(), + ID: name[0], ctx: ctx, out: out, overrides: make(map[string]string), diff --git a/playground/recipe_buildernet.go b/playground/recipe_buildernet.go index 382476ff..7992eaa6 100644 --- a/playground/recipe_buildernet.go +++ b/playground/recipe_buildernet.go @@ -54,7 +54,7 @@ func (b *BuilderNetRecipe) Output(manifest *Manifest) map[string]interface{} { admin := builderHubService.MustGetPort("admin") internal := builderHubService.MustGetPort("internal") - output["builder-hub-http (proxy)"] = fmt.Sprintf("http://localhost:%d", http.HostPort) + output["builder-hub-proxy"] = fmt.Sprintf("http://localhost:%d", http.HostPort) output["builder-hub-admin"] = fmt.Sprintf("http://localhost:%d", admin.HostPort) output["builder-hub-internal"] = fmt.Sprintf("http://localhost:%d", internal.HostPort) diff --git a/utils/logging/logging.go b/utils/logging/logging.go new file mode 100644 index 00000000..82ae818a --- /dev/null +++ b/utils/logging/logging.go @@ -0,0 +1,39 @@ +package logging + +import ( + "log" + "log/slog" + "os" + "time" + + "github.com/phsym/console-slog" +) + +// ConfigureSlog configures the default logger. +func ConfigureSlog(logLevel string) slog.Level { + // We use debug level for trace-level logs. + if logLevel == "trace" { + logLevel = "debug" + } + var level slog.Level + err := level.UnmarshalText([]byte(logLevel)) + if err != nil { + log.Fatalf("invalid log level: %s", logLevel) + } + logger := newConsoleLogger(level <= slog.LevelDebug) + slog.SetDefault(logger) + return level +} + +func newConsoleLogger(debug bool) *slog.Logger { + level := slog.LevelInfo.Level() + if debug { + level = slog.LevelDebug.Level() + } + handler := console.NewHandler(os.Stdout, &console.HandlerOptions{ + Level: level, + TimeFormat: time.DateTime, + Theme: newTheme(), + }) + return slog.New(handler) +} diff --git a/utils/logging/theme.go b/utils/logging/theme.go new file mode 100644 index 00000000..20776d5a --- /dev/null +++ b/utils/logging/theme.go @@ -0,0 +1,64 @@ +package logging + +import ( + "log/slog" + + "github.com/phsym/console-slog" +) + +type themeDef struct { + name string + timestamp console.ANSIMod + source console.ANSIMod + message console.ANSIMod + messageDebug console.ANSIMod + attrKey console.ANSIMod + attrValue console.ANSIMod + attrValueError console.ANSIMod + levelError console.ANSIMod + levelWarn console.ANSIMod + levelInfo console.ANSIMod + levelDebug console.ANSIMod +} + +func (t themeDef) Name() string { return t.name } +func (t themeDef) Timestamp() console.ANSIMod { return t.timestamp } +func (t themeDef) Source() console.ANSIMod { return t.source } +func (t themeDef) Message() console.ANSIMod { return t.message } +func (t themeDef) MessageDebug() console.ANSIMod { return t.messageDebug } +func (t themeDef) AttrKey() console.ANSIMod { return t.attrKey } +func (t themeDef) AttrValue() console.ANSIMod { return t.attrValue } +func (t themeDef) AttrValueError() console.ANSIMod { return t.attrValueError } +func (t themeDef) LevelError() console.ANSIMod { return t.levelError } +func (t themeDef) LevelWarn() console.ANSIMod { return t.levelWarn } +func (t themeDef) LevelInfo() console.ANSIMod { return t.levelInfo } +func (t themeDef) LevelDebug() console.ANSIMod { return t.levelDebug } +func (t themeDef) Level(level slog.Level) console.ANSIMod { + switch { + case level >= slog.LevelError: + return t.LevelError() + case level >= slog.LevelWarn: + return t.LevelWarn() + case level >= slog.LevelInfo: + return t.LevelInfo() + default: + return t.LevelDebug() + } +} + +func newTheme() console.Theme { + return themeDef{ + name: "builder-playground", + timestamp: console.ToANSICode(console.BrightBlack), + source: console.ToANSICode(console.Bold, console.BrightBlack), + message: console.ToANSICode(console.Bold), + messageDebug: console.ToANSICode(console.Faint), + attrKey: console.ToANSICode(console.Yellow, console.Faint, console.Bold), + attrValue: console.ToANSICode(console.Faint), + attrValueError: console.ToANSICode(console.Red), + levelError: console.ToANSICode(console.Red), + levelWarn: console.ToANSICode(console.Yellow), + levelInfo: console.ToANSICode(console.Faint), + levelDebug: console.ToANSICode(console.Cyan, console.Faint), + } +} diff --git a/utils/mainctx/context.go b/utils/mainctx/context.go index 0d432dbb..824bddd6 100644 --- a/utils/mainctx/context.go +++ b/utils/mainctx/context.go @@ -2,7 +2,7 @@ package mainctx import ( "context" - "log" + "log/slog" "os" "os/signal" "syscall" @@ -23,7 +23,7 @@ func init() { syscall.SIGQUIT) go func() { sig := <-sigCh - log.Printf("received signal: %s", sig) + slog.Warn("received signal", "signal", sig) cancel() }() } diff --git a/utils/time_watcher.go b/utils/time_watcher.go index bbcd7db6..614d0ed9 100644 --- a/utils/time_watcher.go +++ b/utils/time_watcher.go @@ -1,20 +1,16 @@ package utils import ( - "log" + "log/slog" "time" ) -var TraceMode bool - // StartTimer starts a timer with the given name and returns a function that prints the elapsed time when called. -// The elapsed time is only printed if TraceMode is enabled. +// The elapsed time is only printed if debug or trace levels are used. func StartTimer(name string) func() { start := time.Now() return func() { - if TraceMode { - elapsed := time.Since(start) - log.Printf("[TRACE] %s: %v\n", name, elapsed) - } + elapsed := time.Since(start) + slog.Debug(name, "elapsed", elapsed) } }