Add structured logging (first version) (#254)

* Introduce new functions to log verbose or on info, use internally the
old verbosity flags
  * allows simplifying certain code parts
* add zerolog for structured json logging
(https://betterprogramming.pub/how-to-use-structured-json-logging-in-golang-applications-7fc5e2751dbd)
* add new flag to toggle structured logging for cli
  * useful when running worker

Future: Worker can add variables to the logger, like experiment name
etc.

----

Example:

With json logging
```
$ ./zbchaos restart broker -v --jsonLogging
{"level":"debug","cli":"zbchaos","time":"2022-11-23T10:58:07+01:00","message":"Connecting to zell-chaos"}
{"level":"debug","cli":"zbchaos","time":"2022-11-23T10:58:07+01:00","message":"Running experiment in self-managed environment."}
{"level":"debug","cli":"zbchaos","time":"2022-11-23T10:58:07+01:00","message":"Successfully created port forwarding tunnel"}
{"level":"debug","cli":"zbchaos","time":"2022-11-23T10:58:07+01:00","message":"Found Broker zell-chaos-zeebe-1 as LEADER for partition 1."}
{"level":"debug","cli":"zbchaos","time":"2022-11-23T10:58:07+01:00","message":"Restarted zell-chaos-zeebe-1"}
```

Normal:
```
$ ./zbchaos restart broker -v
Connecting to zell-chaos
Running experiment in self-managed environment.
Successfully created port forwarding tunnel
Found Broker zell-chaos-zeebe-0 as LEADER for partition 1.
Restarted zell-chaos-zeebe-0
```

go-chaos/cmd/backup.go

@@ -19,15 +19,16 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	apps "k8s.io/api/apps/v1"
-	core "k8s.io/api/core/v1"
-	meta "k8s.io/apimachinery/pkg/apis/meta/v1"
-	"k8s.io/apimachinery/pkg/labels"
 	"net/http"
 	"os"
 	"strconv"
 	"time"
 
+	apps "k8s.io/api/apps/v1"
+	core "k8s.io/api/core/v1"
+	meta "k8s.io/apimachinery/pkg/apis/meta/v1"
+	"k8s.io/apimachinery/pkg/labels"
+
 	"github.com/spf13/cobra"
 	"github.com/zeebe-io/zeebe-chaos/go-chaos/internal"
 )
@@ -350,7 +351,7 @@ func getBackupStatus(port int, backupId string) (*BackupStatus, error) {
 		return nil, err
 	}
 
-	fmt.Printf("Found backup %s with status: %s\n", backupId, backup.Status)
+	internal.LogInfo("Found backup %s with status: %s", backupId, backup.Status)
 
 	return &backup, nil
 }

go-chaos/cmd/connect.go

@@ -55,17 +55,15 @@ var connectBrokers = &cobra.Command{
 		}
 
 		if len(podNames) <= 0 {
-			panic(fmt.Sprintf("Expected to find brokers in current namespace %s, but found nothing\n", k8Client.GetCurrentNamespace()))
+			panic(fmt.Sprintf("Expected to find brokers in current namespace %s, but found nothing", k8Client.GetCurrentNamespace()))
 		}
 
 		for _, pod := range podNames {
 			err = internal.MakeIpReachableForPod(k8Client, pod)
 			if err != nil {
-				if Verbose {
-					fmt.Printf("Error on connection Broker: %s. Error: %s\n", pod, err.Error())
-				}
+				internal.LogVerbose("Error on connection Broker: %s. Error: %s", pod, err.Error())
 			} else {
-				fmt.Printf("Connected %s again, removed unreachable routes.\n", pod)
+				internal.LogInfo("Connected %s again, removed unreachable routes.", pod)
 			}
 		}
 	},
@@ -88,7 +86,7 @@ var connectGateway = &cobra.Command{
 		ensureNoError(err)
 
 		if len(brokerPods.Items) <= 0 {
-			panic(fmt.Sprintf("Expected to find broker(s) in current namespace %s, but found nothing\n", k8Client.GetCurrentNamespace()))
+			panic(fmt.Sprintf("Expected to find broker(s) in current namespace %s, but found nothing", k8Client.GetCurrentNamespace()))
 		}
 
 		gatewayPod := getGatewayPod(k8Client)
@@ -97,10 +95,10 @@ var connectGateway = &cobra.Command{
 			err = internal.MakeIpReachable(k8Client, gatewayPod.Name, brokerPod.Status.PodIP)
 			if err != nil {
 				if Verbose {
-					fmt.Printf("Error on connection gateway: %s. Error: %s\n", gatewayPod.Name, err.Error())
+					internal.LogVerbose("Error on connection gateway: %s. Error: %s", gatewayPod.Name, err.Error())
 				}
 			} else {
-				fmt.Printf("Connected %s again with %s, removed unreachable routes.\n", gatewayPod.Name, brokerPod.Name)
+				internal.LogInfo("Connected %s again with %s, removed unreachable routes.", gatewayPod.Name, brokerPod.Name)
 			}
 		}
 	},

go-chaos/cmd/dataloss_sim.go

@@ -15,7 +15,6 @@
 package cmd
 
 import (
-	"fmt"
 	"github.com/spf13/cobra"
 	"github.com/zeebe-io/zeebe-chaos/go-chaos/internal"
 )
@@ -53,7 +52,7 @@ var prepareCmd = &cobra.Command{
 			panic(err)
 		}
 
-		fmt.Printf("Prepared cluster in namesapce %s\n", k8Client.GetCurrentNamespace())
+		internal.LogInfo("Prepared cluster in namesapce %s", k8Client.GetCurrentNamespace())
 	},
 }
 
@@ -71,7 +70,7 @@ var datalossDelete = &cobra.Command{
 		pod, err := internal.GetBrokerPodForNodeId(k8Client, int32(nodeId))
 
 		if err != nil {
-			fmt.Printf("Failed to get pod with nodeId %d %s\n", nodeId, err)
+			internal.LogInfo("Failed to get pod with nodeId %d %s", nodeId, err)
 			panic(err)
 		}
 
@@ -80,11 +79,11 @@ var datalossDelete = &cobra.Command{
 		internal.SetInitContainerBlockFlag(k8Client, nodeId, "true")
 		err = k8Client.RestartPod(pod.Name)
 		if err != nil {
-			fmt.Printf("Failed to restart pod %s\n", pod.Name)
+			internal.LogInfo("Failed to restart pod %s", pod.Name)
 			panic(err)
 		}
 
-		fmt.Printf("Deleted pod %s in namespace %s\n", pod.Name, k8Client.GetCurrentNamespace())
+		internal.LogInfo("Deleted pod %s in namespace %s", pod.Name, k8Client.GetCurrentNamespace())
 	},
 }
 
@@ -106,8 +105,8 @@ var datalossRecover = &cobra.Command{
 
 		err = k8Client.AwaitReadiness()
 		if err != nil {
-			fmt.Printf("%s\n", err)
+			internal.LogInfo("%s", err)
 		}
-		fmt.Printf("Restarted broker %d\n", nodeId)
+		internal.LogInfo("Restarted broker %d", nodeId)
 	},
 }

go-chaos/cmd/deploy.go

@@ -15,8 +15,6 @@
 package cmd
 
 import (
-	"fmt"
-
 	"github.com/spf13/cobra"
 	"github.com/zeebe-io/zeebe-chaos/go-chaos/internal"
 )
@@ -64,12 +62,12 @@ Defaults to the later, which is useful for experimenting with deployment distrib
 			// deploy multi version
 			err := internal.DeployDifferentVersions(zbClient, int32(multipleVersions))
 			ensureNoError(err)
-			fmt.Printf("Deployed different process models of different types and versions to zeebe!\n")
+			internal.LogInfo("Deployed different process models of different types and versions to zeebe!")
 		} else {
 			processDefinitionKey, err := internal.DeployModel(zbClient, processModelPath)
 			ensureNoError(err)
 
-			fmt.Printf("Deployed given process model %s, under key %d!\n", processModelPath, processDefinitionKey)
+			internal.LogInfo("Deployed given process model %s, under key %d!", processModelPath, processDefinitionKey)
 		}
 	},
 }
@@ -86,6 +84,6 @@ The workers can be used as part of some chaos experiments to complete process in
 		err = k8Client.CreateWorkerDeployment()
 		ensureNoError(err)
 
-		fmt.Printf("Worker successfully deployed to the current namespace: %s\n", k8Client.GetCurrentNamespace())
+		internal.LogInfo("Worker successfully deployed to the current namespace: %s", k8Client.GetCurrentNamespace())
 	},
 }

go-chaos/cmd/disconnect.go

@@ -84,9 +84,7 @@ var disconnectBrokers = &cobra.Command{
 		err = k8Client.ApplyNetworkPatch()
 		ensureNoError(err)
 
-		if Verbose {
-			fmt.Println("Patched statefulset")
-		}
+		internal.LogVerbose("Patched statefulset")
 
 		port := 26500
 		closeFn := k8Client.MustGatewayPortForward(port, port)
@@ -100,7 +98,7 @@ var disconnectBrokers = &cobra.Command{
 		broker2Pod := getBrokerPod(k8Client, zbClient, broker2NodeId, broker2PartitionId, broker2Role)
 
 		if broker1Pod.Name == broker2Pod.Name {
-			fmt.Printf("Expected to disconnect two DIFFERENT brokers %s and %s, but they are the same. Will do nothing.\n", broker1Pod.Name, broker2Pod.Name)
+			internal.LogInfo("Expected to disconnect two DIFFERENT brokers %s and %s, but they are the same. Will do nothing.", broker1Pod.Name, broker2Pod.Name)
 			return
 		}
 
@@ -114,15 +112,11 @@ func getBrokerPod(k8Client internal.K8Client, zbClient zbc.Client, brokerNodeId
 	if brokerNodeId >= 0 {
 		brokerPod, err = internal.GetBrokerPodForNodeId(k8Client, int32(brokerNodeId))
 		ensureNoError(err)
-		if Verbose {
-			fmt.Printf("Found Broker %s with node id %d.\n", brokerPod.Name, brokerNodeId)
-		}
+		internal.LogVerbose("Found Broker %s with node id %d.", brokerPod.Name, brokerNodeId)
 	} else {
 		brokerPod, err = internal.GetBrokerPodForPartitionAndRole(k8Client, zbClient, brokerPartitionId, brokerRole)
 		ensureNoError(err)
-		if Verbose {
-			fmt.Printf("Found Broker %s as %s for partition %d.\n", brokerPod.Name, role, brokerPartitionId)
-		}
+		internal.LogVerbose("Found Broker %s as %s for partition %d.", brokerPod.Name, role, brokerPartitionId)
 	}
 
 	return brokerPod
@@ -154,16 +148,12 @@ var disconnectGateway = &cobra.Command{
 		err = k8Client.ApplyNetworkPatch()
 		ensureNoError(err)
 
-		if Verbose {
-			fmt.Println("Patched statefulset")
-		}
+		internal.LogVerbose("Patched statefulset")
 
 		err = k8Client.ApplyNetworkPatchOnGateway()
 		ensureNoError(err)
 
-		if Verbose {
-			fmt.Println("Patched deployment")
-		}
+		internal.LogVerbose("Patched deployment")
 
 		err = k8Client.AwaitReadiness()
 		ensureNoError(err)
@@ -195,11 +185,11 @@ var disconnectGateway = &cobra.Command{
 func disconnectPods(k8Client internal.K8Client, firstPod *v1.Pod, secondPod *v1.Pod) {
 	err := internal.MakeIpUnreachableForPod(k8Client, secondPod.Status.PodIP, firstPod.Name)
 	ensureNoError(err)
-	fmt.Printf("Disconnect %s from %s\n", firstPod.Name, secondPod.Name)
+	internal.LogInfo("Disconnect %s from %s", firstPod.Name, secondPod.Name)
 
 	if !oneDirection {
 		err = internal.MakeIpUnreachableForPod(k8Client, firstPod.Status.PodIP, secondPod.Name)
 		ensureNoError(err)
-		fmt.Printf("Disconnect %s from %s\n", secondPod.Name, firstPod.Name)
+		internal.LogInfo("Disconnect %s from %s", secondPod.Name, firstPod.Name)
 	}
 }

go-chaos/cmd/publish.go

@@ -16,7 +16,6 @@ package cmd
 
 import (
 	"context"
-	"fmt"
 	"time"
 
 	"github.com/spf13/cobra"
@@ -51,14 +50,12 @@ var publishCmd = &cobra.Command{
 		correlationKey, err := internal.FindCorrelationKeyForPartition(partitionId, int(topology.PartitionsCount))
 		panicOnError(err)
 
-		if Verbose {
-			fmt.Printf("Send message '%s', with correaltion key '%s' (ASCII: %d) \n", msgName, correlationKey, int(correlationKey[0]))
-		}
+		internal.LogVerbose("Send message '%s', with correaltion key '%s' (ASCII: %d) ", msgName, correlationKey, int(correlationKey[0]))
 
 		messageResponse, err := zbClient.NewPublishMessageCommand().MessageName(msgName).CorrelationKey(correlationKey).TimeToLive(time.Minute * 5).Send(context.TODO())
 		partitionIdFromKey := internal.ExtractPartitionIdFromKey(messageResponse.Key)
 
-		fmt.Printf("Message was sent and returned key %d, which corresponds to partition: %d\n", messageResponse.Key, partitionIdFromKey)
+		internal.LogInfo("Message was sent and returned key %d, which corresponds to partition: %d", messageResponse.Key, partitionIdFromKey)
 	},
 }
 

go-chaos/cmd/restart.go

@@ -15,9 +15,8 @@
 package cmd
 
 import (
-	"fmt"
-
 	"github.com/spf13/cobra"
+	"github.com/zeebe-io/zeebe-chaos/go-chaos/internal"
 )
 
 func init() {
@@ -45,7 +44,7 @@ var restartBrokerCmd = &cobra.Command{
 	Long:  `Restarts a Zeebe broker with a certain role and given partition.`,
 	Run: func(cmd *cobra.Command, args []string) {
 		brokerPod := restartBroker(nodeId, partitionId, role, nil)
-		fmt.Printf("Restarted %s\n", brokerPod)
+		internal.LogInfo("Restarted %s", brokerPod)
 	},
 }
 
@@ -55,7 +54,7 @@ var restartGatewayCmd = &cobra.Command{
 	Long:  `Restarts a Zeebe gateway.`,
 	Run: func(cmd *cobra.Command, args []string) {
 		gatewayPod := restartGateway(nil)
-		fmt.Printf("Restarted %s\n", gatewayPod)
+		internal.LogInfo("Restarted %s", gatewayPod)
 	},
 }
 

go-chaos/cmd/root.go

@@ -19,6 +19,7 @@ import (
 	"os"
 
 	"github.com/camunda/zeebe/clients/go/v8/pkg/zbc"
+	"github.com/rs/zerolog/log"
 
 	"github.com/spf13/cobra"
 	"github.com/zeebe-io/zeebe-chaos/go-chaos/internal"
@@ -47,6 +48,7 @@ var Namespace string
 var ClientId string
 var ClientSecret string
 var Audience string
+var JsonLogging bool
 
 var rootCmd = &cobra.Command{
 	Use:   "zbchaos",
@@ -55,6 +57,10 @@ var rootCmd = &cobra.Command{
     Perfect to inject some chaos into your brokers and gateways.`,
 	PersistentPreRun: func(cmd *cobra.Command, args []string) {
 		internal.Verbosity = Verbose
+		internal.JsonLogging = JsonLogging
+		if JsonLogging {
+			internal.JsonLogger = log.With().Str("cli", "zbchaos").Logger()
+		}
 		internal.Namespace = Namespace
 		internal.KubeConfigPath = KubeConfigPath
 		if ClientId != "" && ClientSecret != "" {
@@ -69,6 +75,7 @@ var rootCmd = &cobra.Command{
 
 func init() {
 	rootCmd.PersistentFlags().BoolVarP(&Verbose, "verbose", "v", false, "verbose output")
+	rootCmd.PersistentFlags().BoolVarP(&JsonLogging, "jsonLogging", "", false, "json logging output")
 	rootCmd.PersistentFlags().StringVar(&KubeConfigPath, "kubeconfig", "", "path the the kube config that will be used")
 	rootCmd.PersistentFlags().StringVarP(&Namespace, "namespace", "n", "", "connect to the given namespace")
 	rootCmd.PersistentFlags().StringVarP(&ClientId, "clientId", "c", "", "connect using the given clientId")

go-chaos/cmd/stress.go

@@ -15,8 +15,6 @@
 package cmd
 
 import (
-	"fmt"
-
 	"github.com/spf13/cobra"
 	"github.com/zeebe-io/zeebe-chaos/go-chaos/internal"
 )
@@ -71,7 +69,7 @@ var stressBroker = &cobra.Command{
 		defer zbClient.Close()
 
 		pod := getBrokerPod(k8Client, zbClient, nodeId, partitionId, role)
-		fmt.Printf("Put stress on %s\n", pod.Name)
+		internal.LogInfo("Put stress on %s", pod.Name)
 
 		stressType := internal.StressType{CpuStress: cpuStress, IoStress: ioStress, MemStress: memoryStress}
 		err = internal.PutStressOnPod(k8Client, timeoutSec, pod.Name, stressType)
@@ -89,7 +87,7 @@ var stressGateway = &cobra.Command{
 		ensureNoError(err)
 
 		pod := getGatewayPod(k8Client)
-		fmt.Printf("Put stress on %s\n", pod.Name)
+		internal.LogInfo("Put stress on %s", pod.Name)
 
 		stressType := internal.StressType{CpuStress: cpuStress, IoStress: ioStress, MemStress: memoryStress}
 		err = internal.PutStressOnPod(k8Client, timeoutSec, pod.Name, stressType)

go-chaos/cmd/terminate.go

@@ -54,7 +54,7 @@ var terminateBrokerCmd = &cobra.Command{
 	Run: func(cmd *cobra.Command, args []string) {
 		gracePeriodSec := int64(0)
 		brokerName := restartBroker(nodeId, partitionId, role, &gracePeriodSec)
-		fmt.Printf("Terminated %s\n", brokerName)
+		internal.LogInfo("Terminated %s", brokerName)
 	},
 }
 
@@ -65,7 +65,7 @@ var terminateGatewayCmd = &cobra.Command{
 	Run: func(cmd *cobra.Command, args []string) {
 		gracePeriodSec := int64(0)
 		gatewayPod := restartGateway(&gracePeriodSec)
-		fmt.Printf("Terminated %s\n", gatewayPod)
+		internal.LogInfo("Terminated %s", gatewayPod)
 	},
 }
 
@@ -139,13 +139,13 @@ func restartWorker(all bool, actionName string, gracePeriod *int64) {
 		for _, worker := range workerPods.Items {
 			err = k8Client.RestartPodWithGracePeriod(worker.Name, gracePeriod)
 			ensureNoError(err)
-			fmt.Printf("%s %s\n", actionName, worker.Name)
+			internal.LogInfo("%s %s", actionName, worker.Name)
 		}
 	} else {
 		workerPod := workerPods.Items[0]
 		err = k8Client.RestartPodWithGracePeriod(workerPod.Name, gracePeriod)
 		ensureNoError(err)
 
-		fmt.Printf("%s %s\n", actionName, workerPod.Name)
+		internal.LogInfo("%s %s", actionName, workerPod.Name)
 	}
 }

go-chaos/cmd/topology.go

@@ -18,7 +18,7 @@ import (
 	"context"
 	"fmt"
 	"io"
-	"os"
+	"strings"
 	"text/tabwriter"
 
 	"github.com/camunda/zeebe/clients/go/v8/pkg/pb"
@@ -54,7 +54,9 @@ var topologyCmd = &cobra.Command{
 			panic(err)
 		}
 
-		writeTopologyToOutput(os.Stdout, response)
+		builder := strings.Builder{}
+		writeTopologyToOutput(&builder, response)
+		internal.LogInfo(builder.String())
 	},
 }