more human readable logging pattern (#4763)

### Changes
- Caller (file name) only displayed in debug mode
- Shorter timestamp format except in debug mode
- Field format are now key=value, instead of [key=value] 
- Reduce node info we log during startup, except in debug mode
- Removed connect message

### New Format
```
→ bacalhau serve --orchestrator --compute
12:09:06 | INF Config loaded from: [], and with data-dir /Users/walid/.bacalhau
12:09:06 | INF Starting bacalhau...
12:09:07 | INF Starting connection manager node_id=n-2952ac48-9c5a-4114-8564-60eca482ba2e start_time=2024-12-12T12:09:07.805517+02:00
12:09:07 | INF Attempting to establish connection node_id=n-2952ac48-9c5a-4114-8564-60eca482ba2e
12:09:07 | INF bacalhau node running name=n-2952ac48-9c5a-4114-8564-60eca482ba2e orchestrators=["nats://127.0.0.1:4222"]
12:09:07 | INF handshake successful with node n-2952ac48-9c5a-4114-8564-60eca482ba2e
^C12:09:09 | INF bacalhau node shutting down...
```

### Old Format
```
→ bacalhau-1.5.0 serve --orchestrator --compute
12:09:11.576 | INF cmd/cli/serve/serve.go:102 > Config loaded from: [], and with data-dir /Users/walid/.bacalhau
12:09:11.577 | INF cmd/cli/serve/serve.go:181 > Starting bacalhau...
12:09:11.641 | INF cmd/cli/serve/serve.go:256 > bacalhau node running [address:0.0.0.0:1234] [capacity:"{CPU: 5.60, Memory: 12 GB, Disk: 76 GB, GPU: 0}"] [compute_enabled:true] [engines:["wasm","docker"]] [name:n-2952ac48-9c5a-4114-8564-60eca482ba2e] [orchestrator_address:0.0.0.0:4222] [orchestrator_enabled:true] [orchestrators:["nats://127.0.0.1:4222"]] [publishers:["noop","s3","local"]] [storages:["urldownload","inline","s3"]] [webui_enabled:false]

To connect to this node from the local client, run the following commands in your shell:
export BACALHAU_API_HOST=127.0.0.1
export BACALHAU_API_PORT=1234

A copy of these variables have been written to: /Users/walid/.bacalhau/bacalhau.run
^C12:09:14.077 | INF cmd/cli/serve/serve.go:271 > bacalhau node shutting down...
```


![image](https://github.com/user-attachments/assets/4c102647-c398-48e9-92a7-6cb357017b4d)


<!-- This is an auto-generated comment: release notes by coderabbit.ai
-->

## Summary by CodeRabbit

- **New Features**
- Introduced a debug mode for enhanced logging, providing detailed
startup information when enabled.

- **Bug Fixes**
	- Improved error handling for configuration setup and logging issues.

- **Documentation**
- Updated log output format based on the log level, simplifying messages
in non-debug mode.

<!-- end of auto-generated comment: release notes by coderabbit.ai -->

Author: wdbaruni

cmd/cli/serve/serve.go

@@ -229,42 +229,46 @@ func serve(cmd *cobra.Command, cfg types.Bacalhau, fsRepo *repo.FsRepo) error {
 		}()
 	}
 
+	isDebug := system.IsDebugMode()
 	startupLog := log.Info().
-		Str("name", sysmeta.NodeName).
-		Str("address", fmt.Sprintf("%s:%d", hostAddress, cfg.API.Port)).
-		Bool("compute_enabled", cfg.Compute.Enabled).
-		Bool("orchestrator_enabled", cfg.Orchestrator.Enabled).
-		Bool("webui_enabled", cfg.WebUI.Enabled)
-	if cfg.Compute.Enabled {
-		capacity := standardNode.ComputeNode.Capacity.GetMaxCapacity(ctx)
+		Str("name", sysmeta.NodeName)
+
+	if isDebug {
 		startupLog.
-			Strs("engines", standardNode.ComputeNode.Executors.Keys(ctx)).
-			Strs("publishers", standardNode.ComputeNode.Publishers.Keys(ctx)).
-			Strs("storages", standardNode.ComputeNode.Storages.Keys(ctx)).
-			Strs("orchestrators", cfg.Compute.Orchestrators).
-			Str("capacity", capacity.String())
-
-		if len(cfg.Compute.AllowListedLocalPaths) > 0 {
-			startupLog.Strs("volumes", cfg.Compute.AllowListedLocalPaths)
+			Str("address", fmt.Sprintf("%s:%d", hostAddress, cfg.API.Port)).
+			Bool("compute_enabled", cfg.Compute.Enabled).
+			Bool("orchestrator_enabled", cfg.Orchestrator.Enabled).
+			Bool("webui_enabled", cfg.WebUI.Enabled)
+	}
+	if cfg.Compute.Enabled {
+		startupLog.Strs("orchestrators", cfg.Compute.Orchestrators)
+
+		if isDebug {
+			capacity := standardNode.ComputeNode.Capacity.GetMaxCapacity(ctx)
+			startupLog.
+				Strs("engines", standardNode.ComputeNode.Executors.Keys(ctx)).
+				Strs("publishers", standardNode.ComputeNode.Publishers.Keys(ctx)).
+				Strs("storages", standardNode.ComputeNode.Storages.Keys(ctx)).
+				Str("capacity", capacity.String())
+			if len(cfg.Compute.AllowListedLocalPaths) > 0 {
+				startupLog.Strs("volumes", cfg.Compute.AllowListedLocalPaths)
+			}
 		}
 	}
 
 	if cfg.Orchestrator.Enabled {
-		startupLog.Str("orchestrator_address",
-			fmt.Sprintf("%s:%d", cfg.Orchestrator.Host, cfg.Orchestrator.Port))
+		if isDebug {
+			startupLog.Str("orchestrator_address",
+				fmt.Sprintf("%s:%d", cfg.Orchestrator.Host, cfg.Orchestrator.Port))
+		}
 	}
 	startupLog.Msg("bacalhau node running")
 
 	envvars := buildEnvVariables(cfg)
-	cmd.Println()
-	cmd.Println("To connect to this node from the local client, run the following commands in your shell:")
-	cmd.Println(envvars)
-
 	riPath, err := fsRepo.WriteRunInfo(ctx, envvars)
 	if err != nil {
 		return err
 	}
-	cmd.Printf("A copy of these variables have been written to: %s\n", riPath)
 	defer os.Remove(riPath)
 
 	<-ctx.Done() // block until killed

pkg/logger/logger.go

@@ -188,26 +188,28 @@ func defaultLogFormat(w *zerolog.ConsoleWriter) {
 	isTerminal := isatty.IsTerminal(os.Stdout.Fd())
 	w.Out = os.Stdout
 	w.NoColor = !isTerminal
-	w.TimeFormat = "15:04:05.999 |"
-	w.PartsOrder = []string{
-		zerolog.TimestampFieldName,
-		zerolog.LevelFieldName,
-		zerolog.CallerFieldName,
-		zerolog.MessageFieldName,
-	}
-
-	// TODO: figure out a way to show the custom fields at the beginning of the log line rather than at the end.
-	//  Adding the fields to the parts section didn't help as it just printed the fields twice.
-	w.FormatFieldName = func(i interface{}) string {
-		return fmt.Sprintf("[%s:", i)
-	}
 
-	w.FormatFieldValue = func(i interface{}) string {
-		// don't print nil in case field value wasn't preset. e.g. no nodeID
-		if i == nil {
-			i = ""
+	// Get the current log level to determine format
+	level := zerolog.GlobalLevel()
+	isDebug := level <= zerolog.DebugLevel
+
+	if isDebug {
+		// Debug mode - show detailed information
+		w.TimeFormat = "15:04:05.999 |"
+		w.PartsOrder = []string{
+			zerolog.TimestampFieldName,
+			zerolog.LevelFieldName,
+			zerolog.CallerFieldName,
+			zerolog.MessageFieldName,
+		}
+	} else {
+		// Normal mode - simplified, user-friendly format
+		w.TimeFormat = "15:04:05 |"
+		w.PartsOrder = []string{
+			zerolog.TimestampFieldName,
+			zerolog.LevelFieldName,
+			zerolog.MessageFieldName,
 		}
-		return fmt.Sprintf("%s]", i)
 	}
 }
 

pkg/logger/logger_test.go

@@ -33,13 +33,12 @@ func TestConfigureLogging(t *testing.T) {
 	subsubpackage.TestLog("testing error logging", "testing message")
 
 	actual := logging.String()
-	// Like 12:47:40.875 | ERR pkg/logger/testpackage/subpackage/subsubpackage/testutil.go:12 > testing message error="testing error logging" [stack:[{"func":"TestLog","line":"10","source":"testutil.go"},{"func":"TestConfigureLogging","line":"27","source":"logger_test.go"},...]]
+	// Like 12:47:40.875 | ERR  > testing message error="testing error logging" stack=[{"func":"TestLog","line":"10","source":"testutil.go"},{"func":"TestConfigureLogging","line":"27","source":"logger_test.go"},...]
 	t.Log(actual)
 
 	assert.Contains(t, actual, "testing message", "Log statement doesn't contain the log message")
 	assert.Contains(t, actual, `error="testing error logging"`, "Log statement doesn't contain the logged error")
-	assert.Contains(t, actual, "pkg/logger/testpackage/subpackage/subsubpackage/testutil.go", "Log statement doesn't contain the full package path")
-	assert.Contains(t, actual, `stack:[{"func":"TestLog","line":`, "Log statement didn't automatically include the error's stacktrace")
+	assert.Contains(t, actual, `stack=[{"func":"TestLog","line":`, "Log statement didn't automatically include the error's stacktrace")
 }
 
 func TestParseAndConfigureLogging(t *testing.T) {