From 61e0f7df799aad3d00d81f3b51b50d94a01cf57e Mon Sep 17 00:00:00 2001
From: Tim Serong <tserong@suse.com>
Date: Tue, 16 Jul 2024 23:20:03 +1000
Subject: [PATCH] udev: Use structured logging in ActionHandler

With this we now see messages like:

```
time="2024-07-17T01:37:24Z" level=debug msg="Prepare to handle udev action" udevAction=add udevEnv="map[..big chunk of stuff here..]"

time="2024-07-17T01:37:24Z" level=info msg="udev action triggering scanner wake" device=/dev/sda kind=BlockDevice name=b3270eab097d4515bac2d595665ac618 namespace=longhorn-system udevAction=add

time="2024-07-17T01:44:23Z" level=info msg="udev action triggering scanner wake" device=/dev/sda kind=BlockDevice name=b3270eab097d4515bac2d595665ac618 namespace=longhorn-system udevAction=remove
```

And in the case of an unidentifiable device:

```
time="2024-07-17T01:44:39Z" level=info msg="Skip adding non-identifiable block device" device=/dev/sda
```

Signed-off-by: Tim Serong <tserong@suse.com>
---
 pkg/udev/uevent.go | 22 ++++++++++++++++++----
 1 file changed, 18 insertions(+), 4 deletions(-)

diff --git a/pkg/udev/uevent.go b/pkg/udev/uevent.go
index 5b22810c..bde4635a 100644
--- a/pkg/udev/uevent.go
+++ b/pkg/udev/uevent.go
@@ -102,7 +102,10 @@ func (u *Udev) ActionHandler(uevent netlink.UEvent) {
 	if !udevDevice.IsDisk() && !udevDevice.IsPartition() {
 		return
 	}
-	logrus.Debugf("Prepare to handle event: %s, env: %+v", uevent.Action, uevent.Env)
+	logrus.WithFields(logrus.Fields{
+		"udevAction": uevent.Action,
+		"udevEnv":    fmt.Sprintf("%+v", uevent.Env),
+	}).Debug("Prepare to handle udev action")
 
 	devPath := udevDevice.GetDevName()
 	var disk *block.Disk
@@ -135,7 +138,10 @@ func (u *Udev) ActionHandler(uevent netlink.UEvent) {
 	} else {
 		parentPath, err := block.GetParentDevName(devPath)
 		if err != nil {
-			logrus.Errorf("failed to get parent dev name, %s", err.Error())
+			logrus.WithFields(logrus.Fields{
+				"device": devPath,
+				"err":    err.Error(),
+			}).Error("Failed to get parent device name")
 		}
 		part = u.scanner.BlockInfo.GetPartitionByDevPath(parentPath, devPath)
 		disk = part.Disk
@@ -151,7 +157,9 @@ func (u *Udev) ActionHandler(uevent netlink.UEvent) {
 	}
 
 	if bd.Name == "" {
-		logrus.Infof("Skip adding non-identifiable block device %s", bd.Spec.DevPath)
+		logrus.WithFields(logrus.Fields{
+			"device": bd.Spec.DevPath,
+		}).Info("Skip adding non-identifiable block device")
 		return
 	}
 
@@ -161,7 +169,13 @@ func (u *Udev) ActionHandler(uevent netlink.UEvent) {
 
 func (u *Udev) wakeUpScanner(uevent netlink.UEvent, bd *v1beta1.BlockDevice) {
 	utils.CallerWithCondLock(u.scanner.Cond, func() any {
-		logrus.Infof("Wake up scanner with %s operation with blockdevice: %s, device: %s", uevent.Action, bd.Name, bd.Spec.DevPath)
+		logrus.WithFields(logrus.Fields{
+			"namespace":  bd.Namespace,
+			"name":       bd.Name,
+			"kind":       "BlockDevice",
+			"udevAction": uevent.Action,
+			"device":     bd.Spec.DevPath,
+		}).Info("udev action triggering scanner wake")
 		u.scanner.Cond.Signal()
 		return nil
 	})