excessive logging from control plane & log levels/verbosity not respected

[jakekeeys]

a cursory glance at the code suggests some thought was given to log levels and verbosity but it doesn't seem to have been wired up here or in the csi-grpc-proxy
most of the noise appears to come from the csi-driver and csi-proxy

which is logging a combined 6 lines per second in my small home lab environment with about 20 volumes
the contents of the logs appear to be the result of idle metric collection for volumes

2023-10-24 10:36:39.297 | executing mount command: findmnt --mountpoint /var/lib/kubelet/pods/31726adb-48d9-4f7c-a8e1-145279093608/volumes/kubernetes.io~csi/pvc-429e3c44-afdc-40a8-9374-c8b2570198f8/mount --output source,target,fstype,label,options,avail,size,used -b -J --nofsroot |  
-- | -- | --
  |   | 2023-10-24 10:36:39.254 | executing mount command: findmnt --mountpoint /var/lib/kubelet/pods/31726adb-48d9-4f7c-a8e1-145279093608/volumes/kubernetes.io~csi/pvc-429e3c44-afdc-40a8-9374-c8b2570198f8/mount --output source,target,fstype,label,options -b -J --nofsroot |  
  |   | 2023-10-24 10:36:39.222 | executing mount command: findmnt --mountpoint /var/lib/kubelet/pods/31726adb-48d9-4f7c-a8e1-145279093608/volumes/kubernetes.io~csi/pvc-429e3c44-afdc-40a8-9374-c8b2570198f8/mount/block_device --output source,target,fstype,label,options -b -J --nofsroot |  
  |   | 2023-10-24 10:36:39.206 | executing filesystem command: realpath /dev/loop0 |  
  |   | 2023-10-24 10:36:39.115 | executing filesystem command: lsblk -a -b -l -J -O |  
  |   | 2023-10-24 10:36:39.096 | executing filesystem command: realpath /var/lib/kubelet/pods/31726adb-48d9-4f7c-a8e1-145279093608/volumes/kubernetes.io~csi/pvc-429e3c44-afdc-40a8-9374-c8b2570198f8/mount |  
  |   | 2023-10-24 10:36:39.059 | executing mount command: findmnt --mountpoint /var/lib/kubelet/pods/31726adb-48d9-4f7c-a8e1-145279093608/volumes/kubernetes.io~csi/pvc-429e3c44-afdc-40a8-9374-c8b2570198f8/mount --output source,target,fstype,label,options -b -J --nofsroot |  
  |   | 2023-10-24 10:36:39.019 | executing mount command: findmnt --mountpoint /var/lib/kubelet/pods/31726adb-48d9-4f7c-a8e1-145279093608/volumes/kubernetes.io~csi/pvc-429e3c44-afdc-40a8-9374-c8b2570198f8/mount --output source,target,fstype,label,options -b -J --nofsroot |  
  |   | 2023-10-24 10:36:39.016 | 2023/10/24 09:36:39 request headers map[Content-Type:[application/grpc] Grpc-Accept-Encoding:[gzip] Grpc-Timeout:[119984m] Te:[trailers] User-Agent:[grpc-go/1.54.0]] |  
  |   | 2023-10-24 10:36:39.016 | 2023/10/24 09:36:39 request (://localhost) POST /csi.v1.Node/NodeGetVolumeStats HTTP/2.0 |  
  |   | 2023-10-24 10:36:39.002 | 2023/10/24 09:36:39 request headers map[Content-Type:[application/grpc] Grpc-Accept-Encoding:[gzip] Grpc-Timeout:[119999m] Te:[trailers] User-Agent:[grpc-go/1.54.0]] |  
  |   | 2023-10-24 10:36:39.002 | 2023/10/24 09:36:39 request (://localhost) POST /csi.v1.Node/NodeGetCapabilities HTTP/2.0

i've commented out the worse offenders in the following 2 commits which basically negates the above
jakekeeys@8b4e53a
jakekeeys/csi-grpc-proxy@d941a2e

[travisghansen]

Yeah, those need cleaned up! I need to pass in the logger to the util classes and then replace console.log. For the proxy maybe just wrap it in a debug env var or something.

[tobz]

+1 on this.

The current logging situation makes debugging any problems an unreasonably difficult process.

[travisghansen]

That depends on who is debugging ;) usually I am asking for logs and the current data is extremely helpful. The project however is certainly mature enough however at this point that I will indeed implement this differently.

[tobz]

Having the current set of logs be emitted by default would be fine... if everything was actually in a consistent log format, with commensurate log levels applied. I'm fine with filtering out unnecessary logs before they're shipped out of the cluster (even if it's slightly suboptimal) but currently, there's no reasonable way (short of hand-crafting patterns to match all of the various logging categories) to actually process them consistently.

Happy to try and submit a PR for some of this (bring solutions, not problems, etc etc) unless you already have something in the works.

[travisghansen]

Always happy for contributions but it really shouldn't be overly difficult for me to add this. All of the points are well received and agreed with by my part!