Use slog and improve logging (#290)

Default run (no flags):
<img width="1920" height="835" alt="Screenshot_20260105_155531"
src="https://github.com/user-attachments/assets/7d98bca1-0cf3-4d36-b384-accb0ff83955"
/>

With `--log-level=trace` or `--log-level=debug`:
<img width="1920" height="1005" alt="Screenshot_20260105_161730"
src="https://github.com/user-attachments/assets/d867596a-7eca-4df1-b621-bd43583d00e1"
/>

Author: canercidam

go.mod

@@ -10,13 +10,15 @@ 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/go-template v1.0.0
 	github.com/flashbots/mev-boost-relay v0.32.0-rc2
 	github.com/go-chi/httplog/v2 v2.1.1
 	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
@@ -93,6 +95,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

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=
@@ -357,6 +359,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=

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,50 +426,53 @@ 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 {
 		dockerRunner.Stop(keepFlag)
 		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 {

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

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),

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)
 

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)
+}

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),
+	}
+}