diff --git a/cmd/cephcsi.go b/cmd/cephcsi.go index 4525565f0..a17e78722 100644 --- a/cmd/cephcsi.go +++ b/cmd/cephcsi.go @@ -122,8 +122,7 @@ func main() { } os.Exit(0) } - - klog.V(1).Infof("Driver version: %s and Git version: %s", util.DriverVersion, util.GitCommit) + util.DefaultLog("Driver version: %s and Git version: %s", util.DriverVersion, util.GitCommit) var cp util.CachePersister if conf.Vtype == "" { @@ -150,7 +149,7 @@ func main() { if pidErr != nil { klog.Errorf("Failed to get the PID limit, can not reconfigure: %v", pidErr) } else { - klog.V(1).Infof("Initial PID limit is set to %d", currentLimit) + util.DefaultLog("Initial PID limit is set to %d", currentLimit) err = util.SetPIDLimit(conf.PidLimit) if err != nil { klog.Errorf("Failed to set new PID limit to %d: %v", conf.PidLimit, err) @@ -159,7 +158,7 @@ func main() { if conf.PidLimit == -1 { s = " (max)" } - klog.V(1).Infof("Reconfigured PID limit to %d%s", conf.PidLimit, s) + util.DefaultLog("Reconfigured PID limit to %d%s", conf.PidLimit, s) } } } @@ -178,7 +177,7 @@ func main() { } } - klog.V(1).Infof("Starting driver type: %v with name: %v", conf.Vtype, dname) + util.DefaultLog("Starting driver type: %v with name: %v", conf.Vtype, dname) switch conf.Vtype { case rbdType: validateCloneDepthFlag(&conf) diff --git a/internal/cephfs/controllerserver.go b/internal/cephfs/controllerserver.go index f0ae06330..c1051ed32 100644 --- a/internal/cephfs/controllerserver.go +++ b/internal/cephfs/controllerserver.go @@ -136,9 +136,8 @@ func (cs *ControllerServer) CreateVolume(ctx context.Context, req *csi.CreateVol return nil, err } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully created backing volume named %s for request name %s"), + util.DebugLog(ctx, "cephfs: successfully created backing volume named %s for request name %s", vID.FsSubvolName, requestName) - volumeContext := req.GetParameters() volumeContext["subvolumeName"] = vID.FsSubvolName volume := &csi.Volume{ @@ -185,7 +184,7 @@ func (cs *ControllerServer) deleteVolumeDeprecated(ctx context.Context, req *csi // mons may have changed since create volume, // retrieve the latest mons and override old mons if mon, secretsErr := util.GetMonValFromSecret(secrets); secretsErr == nil && len(mon) > 0 { - klog.V(3).Infof(util.Log(ctx, "overriding monitors [%q] with [%q] for volume %s"), ce.VolOptions.Monitors, mon, volID) + util.ExtendedLog(ctx, "overriding monitors [%q] with [%q] for volume %s", ce.VolOptions.Monitors, mon, volID) ce.VolOptions.Monitors = mon } @@ -218,7 +217,7 @@ func (cs *ControllerServer) deleteVolumeDeprecated(ctx context.Context, req *csi return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully deleted volume %s"), volID) + util.DebugLog(ctx, "cephfs: successfully deleted volume %s", volID) return &csi.DeleteVolumeResponse{}, nil } @@ -312,7 +311,7 @@ func (cs *ControllerServer) DeleteVolume(ctx context.Context, req *csi.DeleteVol return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully deleted volume %s"), volID) + util.DebugLog(ctx, "cephfs: successfully deleted volume %s", volID) return &csi.DeleteVolumeResponse{}, nil } diff --git a/internal/cephfs/fsjournal.go b/internal/cephfs/fsjournal.go index 6f3105b05..8109f04bd 100644 --- a/internal/cephfs/fsjournal.go +++ b/internal/cephfs/fsjournal.go @@ -21,8 +21,6 @@ import ( "errors" "github.com/ceph/ceph-csi/internal/util" - - klog "k8s.io/klog/v2" ) // volumeIdentifier structure contains an association between the CSI VolumeID to its subvolume @@ -96,7 +94,7 @@ func checkVolExists(ctx context.Context, volOptions *volumeOptions, secret map[s return nil, err } - klog.V(4).Infof(util.Log(ctx, "Found existing volume (%s) with subvolume name (%s) for request (%s)"), + util.DebugLog(ctx, "Found existing volume (%s) with subvolume name (%s) for request (%s)", vid.VolumeID, vid.FsSubvolName, volOptions.RequestName) return &vid, nil @@ -177,7 +175,7 @@ func reserveVol(ctx context.Context, volOptions *volumeOptions, secret map[strin return nil, err } - klog.V(4).Infof(util.Log(ctx, "Generated Volume ID (%s) and subvolume name (%s) for request name (%s)"), + util.DebugLog(ctx, "Generated Volume ID (%s) and subvolume name (%s) for request name (%s)", vid.VolumeID, vid.FsSubvolName, volOptions.RequestName) return &vid, nil diff --git a/internal/cephfs/nodeserver.go b/internal/cephfs/nodeserver.go index a6197ef2e..cea6662a7 100644 --- a/internal/cephfs/nodeserver.go +++ b/internal/cephfs/nodeserver.go @@ -121,7 +121,7 @@ func (ns *NodeServer) NodeStageVolume(ctx context.Context, req *csi.NodeStageVol } if isMnt { - klog.V(4).Infof(util.Log(ctx, "cephfs: volume %s is already mounted to %s, skipping"), volID, stagingTargetPath) + util.DebugLog(ctx, "cephfs: volume %s is already mounted to %s, skipping", volID, stagingTargetPath) return &csi.NodeStageVolumeResponse{}, nil } @@ -130,7 +130,7 @@ func (ns *NodeServer) NodeStageVolume(ctx context.Context, req *csi.NodeStageVol return nil, err } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully mounted volume %s to %s"), volID, stagingTargetPath) + util.DebugLog(ctx, "cephfs: successfully mounted volume %s to %s", volID, stagingTargetPath) return &csi.NodeStageVolumeResponse{}, nil } @@ -152,7 +152,7 @@ func (*NodeServer) mount(ctx context.Context, volOptions *volumeOptions, req *cs return status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "cephfs: mounting volume %s with %s"), volID, m.name()) + util.DebugLog(ctx, "cephfs: mounting volume %s with %s", volID, m.name()) readOnly := "ro" fuseMountOptions := strings.Split(volOptions.FuseMountOptions, ",") @@ -234,7 +234,7 @@ func (ns *NodeServer) NodePublishVolume(ctx context.Context, req *csi.NodePublis } if isMnt { - klog.V(4).Infof(util.Log(ctx, "cephfs: volume %s is already bind-mounted to %s"), volID, targetPath) + util.DebugLog(ctx, "cephfs: volume %s is already bind-mounted to %s", volID, targetPath) return &csi.NodePublishVolumeResponse{}, nil } @@ -245,7 +245,7 @@ func (ns *NodeServer) NodePublishVolume(ctx context.Context, req *csi.NodePublis return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully bind-mounted volume %s to %s"), volID, targetPath) + util.DebugLog(ctx, "cephfs: successfully bind-mounted volume %s to %s", volID, targetPath) return &csi.NodePublishVolumeResponse{}, nil } @@ -276,7 +276,7 @@ func (ns *NodeServer) NodeUnpublishVolume(ctx context.Context, req *csi.NodeUnpu return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully unbinded volume %s from %s"), req.GetVolumeId(), targetPath) + util.DebugLog(ctx, "cephfs: successfully unbinded volume %s from %s", req.GetVolumeId(), targetPath) return &csi.NodeUnpublishVolumeResponse{}, nil } @@ -301,7 +301,7 @@ func (ns *NodeServer) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstag return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "cephfs: successfully unmounted volume %s from %s"), req.GetVolumeId(), stagingTargetPath) + util.DebugLog(ctx, "cephfs: successfully unmounted volume %s from %s", req.GetVolumeId(), stagingTargetPath) return &csi.NodeUnstageVolumeResponse{}, nil } diff --git a/internal/cephfs/util.go b/internal/cephfs/util.go index 1d3b1bc93..b7482ef27 100644 --- a/internal/cephfs/util.go +++ b/internal/cephfs/util.go @@ -29,7 +29,6 @@ import ( "github.com/container-storage-interface/spec/lib/go/csi" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" - klog "k8s.io/klog/v2" ) type volumeID string @@ -45,7 +44,7 @@ func execCommand(ctx context.Context, program string, args ...string) (stdout, s cmd.Stdout = &stdoutBuf cmd.Stderr = &stderrBuf - klog.V(4).Infof(util.Log(ctx, "cephfs: EXEC %s %s"), program, sanitizedArgs) + util.DebugLog(ctx, "cephfs: EXEC %s %s", program, sanitizedArgs) if err := cmd.Run(); err != nil { if cmd.Process == nil { diff --git a/internal/cephfs/volume.go b/internal/cephfs/volume.go index f109f4654..9c89e1075 100644 --- a/internal/cephfs/volume.go +++ b/internal/cephfs/volume.go @@ -116,7 +116,7 @@ func createVolume(ctx context.Context, volOptions *volumeOptions, cr *util.Crede klog.Errorf(util.Log(ctx, "failed to create subvolume group %s, for the vol %s(%s)"), volOptions.SubvolumeGroup, string(volID), err) return err } - klog.V(4).Infof(util.Log(ctx, "cephfs: created subvolume group %s"), volOptions.SubvolumeGroup) + util.DebugLog(ctx, "cephfs: created subvolume group %s", volOptions.SubvolumeGroup) clusterAdditionalInfo[volOptions.ClusterID].subVolumeGroupCreated = true } @@ -253,7 +253,7 @@ func purgeVolumeDeprecated(ctx context.Context, volID volumeID, adminCr *util.Cr } } else { if !pathExists(volRootDeleting) { - klog.V(4).Infof(util.Log(ctx, "cephfs: volume %s not found, assuming it to be already deleted"), volID) + util.DebugLog(ctx, "cephfs: volume %s not found, assuming it to be already deleted", volID) return nil } } diff --git a/internal/cephfs/volumemounter.go b/internal/cephfs/volumemounter.go index aa6874e9f..d5020c551 100644 --- a/internal/cephfs/volumemounter.go +++ b/internal/cephfs/volumemounter.go @@ -85,10 +85,10 @@ func loadAvailableMounters(conf *util.Config) error { } if conf.ForceKernelCephFS || util.CheckKernelSupport(release, quotaSupport) { - klog.V(1).Infof("loaded mounter: %s", volumeMounterKernel) + util.DefaultLog("loaded mounter: %s", volumeMounterKernel) availableMounters = append(availableMounters, volumeMounterKernel) } else { - klog.V(1).Infof("kernel version < 4.17 might not support quota feature, hence not loading kernel client") + util.DefaultLog("kernel version < 4.17 might not support quota feature, hence not loading kernel client") } } @@ -96,7 +96,7 @@ func loadAvailableMounters(conf *util.Config) error { if err != nil { klog.Errorf("failed to run ceph-fuse %v", err) } else { - klog.V(1).Infof("loaded mounter: %s", volumeMounterFuse) + util.DefaultLog("loaded mounter: %s", volumeMounterFuse) availableMounters = append(availableMounters, volumeMounterFuse) } @@ -131,7 +131,7 @@ func newMounter(volOptions *volumeOptions) (volumeMounter, error) { if chosenMounter == "" { // Otherwise pick whatever is left chosenMounter = availableMounters[0] - klog.V(4).Infof("requested mounter: %s, chosen mounter: %s", wantMounter, chosenMounter) + util.DebugLogMsg("requested mounter: %s, chosen mounter: %s", wantMounter, chosenMounter) } // Create the mounter diff --git a/internal/csi-common/controllerserver-default.go b/internal/csi-common/controllerserver-default.go index 8ab7a541c..0917316db 100644 --- a/internal/csi-common/controllerserver-default.go +++ b/internal/csi-common/controllerserver-default.go @@ -24,7 +24,6 @@ import ( "github.com/container-storage-interface/spec/lib/go/csi" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" - klog "k8s.io/klog/v2" ) // DefaultControllerServer points to default driver @@ -60,7 +59,7 @@ func (cs *DefaultControllerServer) GetCapacity(ctx context.Context, req *csi.Get // ControllerGetCapabilities implements the default GRPC callout. // Default supports all capabilities func (cs *DefaultControllerServer) ControllerGetCapabilities(ctx context.Context, req *csi.ControllerGetCapabilitiesRequest) (*csi.ControllerGetCapabilitiesResponse, error) { - klog.V(5).Infof(util.Log(ctx, "Using default ControllerGetCapabilities")) + util.TraceLog(ctx, "Using default ControllerGetCapabilities") return &csi.ControllerGetCapabilitiesResponse{ Capabilities: cs.Driver.cap, diff --git a/internal/csi-common/driver.go b/internal/csi-common/driver.go index 1e6df9277..9f4bf4e34 100644 --- a/internal/csi-common/driver.go +++ b/internal/csi-common/driver.go @@ -23,6 +23,8 @@ import ( "google.golang.org/grpc/codes" "google.golang.org/grpc/status" klog "k8s.io/klog/v2" + + "github.com/ceph/ceph-csi/internal/util" ) // CSIDriver stores driver information @@ -85,7 +87,7 @@ func (d *CSIDriver) AddControllerServiceCapabilities(cl []csi.ControllerServiceC var csc []*csi.ControllerServiceCapability for _, c := range cl { - klog.V(1).Infof("Enabling controller service capability: %v", c.String()) + util.DefaultLog("Enabling controller service capability: %v", c.String()) csc = append(csc, NewControllerServiceCapability(c)) } @@ -96,7 +98,7 @@ func (d *CSIDriver) AddControllerServiceCapabilities(cl []csi.ControllerServiceC func (d *CSIDriver) AddVolumeCapabilityAccessModes(vc []csi.VolumeCapability_AccessMode_Mode) []*csi.VolumeCapability_AccessMode { var vca []*csi.VolumeCapability_AccessMode for _, c := range vc { - klog.V(1).Infof("Enabling volume access mode: %v", c.String()) + util.DefaultLog("Enabling volume access mode: %v", c.String()) vca = append(vca, NewVolumeCapabilityAccessMode(c)) } d.vc = vca diff --git a/internal/csi-common/identityserver-default.go b/internal/csi-common/identityserver-default.go index dd2c514fd..f9884758c 100644 --- a/internal/csi-common/identityserver-default.go +++ b/internal/csi-common/identityserver-default.go @@ -24,7 +24,6 @@ import ( "github.com/container-storage-interface/spec/lib/go/csi" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" - klog "k8s.io/klog/v2" ) // DefaultIdentityServer stores driver object @@ -34,7 +33,7 @@ type DefaultIdentityServer struct { // GetPluginInfo returns plugin information func (ids *DefaultIdentityServer) GetPluginInfo(ctx context.Context, req *csi.GetPluginInfoRequest) (*csi.GetPluginInfoResponse, error) { - klog.V(5).Infof(util.Log(ctx, "Using default GetPluginInfo")) + util.TraceLog(ctx, "Using default GetPluginInfo") if ids.Driver.name == "" { return nil, status.Error(codes.Unavailable, "Driver name not configured") @@ -57,7 +56,7 @@ func (ids *DefaultIdentityServer) Probe(ctx context.Context, req *csi.ProbeReque // GetPluginCapabilities returns plugin capabilities func (ids *DefaultIdentityServer) GetPluginCapabilities(ctx context.Context, req *csi.GetPluginCapabilitiesRequest) (*csi.GetPluginCapabilitiesResponse, error) { - klog.V(5).Infof(util.Log(ctx, "Using default capabilities")) + util.TraceLog(ctx, "Using default capabilities") return &csi.GetPluginCapabilitiesResponse{ Capabilities: []*csi.PluginCapability{ { diff --git a/internal/csi-common/nodeserver-default.go b/internal/csi-common/nodeserver-default.go index b4ce5ed4a..33fa0901b 100644 --- a/internal/csi-common/nodeserver-default.go +++ b/internal/csi-common/nodeserver-default.go @@ -54,7 +54,7 @@ func (ns *DefaultNodeServer) NodeExpandVolume(ctx context.Context, req *csi.Node // NodeGetInfo returns node ID func (ns *DefaultNodeServer) NodeGetInfo(ctx context.Context, req *csi.NodeGetInfoRequest) (*csi.NodeGetInfoResponse, error) { - klog.V(5).Infof(util.Log(ctx, "Using default NodeGetInfo")) + util.TraceLog(ctx, "Using default NodeGetInfo") csiTopology := &csi.Topology{ Segments: ns.Driver.topology, @@ -68,7 +68,7 @@ func (ns *DefaultNodeServer) NodeGetInfo(ctx context.Context, req *csi.NodeGetIn // NodeGetCapabilities returns RPC unknow capability func (ns *DefaultNodeServer) NodeGetCapabilities(ctx context.Context, req *csi.NodeGetCapabilitiesRequest) (*csi.NodeGetCapabilitiesResponse, error) { - klog.V(5).Infof(util.Log(ctx, "Using default NodeGetCapabilities")) + util.TraceLog(ctx, "Using default NodeGetCapabilities") return &csi.NodeGetCapabilitiesResponse{ Capabilities: []*csi.NodeServiceCapability{ diff --git a/internal/csi-common/server.go b/internal/csi-common/server.go index 6068da5ef..abf31539e 100644 --- a/internal/csi-common/server.go +++ b/internal/csi-common/server.go @@ -29,6 +29,8 @@ import ( "github.com/prometheus/client_golang/prometheus" "google.golang.org/grpc" klog "k8s.io/klog/v2" + + "github.com/ceph/ceph-csi/internal/util" ) // NonBlockingGRPCServer defines Non blocking GRPC server interfaces @@ -113,7 +115,7 @@ func (s *nonBlockingGRPCServer) serve(endpoint, hstOptions string, ids csi.Ident if ns != nil { csi.RegisterNodeServer(server, ns) } - klog.V(1).Infof("Listening for connections on address: %#v", listener.Addr()) + util.DefaultLog("Listening for connections on address: %#v", listener.Addr()) if metrics { ho := strings.Split(hstOptions, ",") if len(ho) != 3 { diff --git a/internal/csi-common/utils.go b/internal/csi-common/utils.go index 05c198a06..164baa7f0 100644 --- a/internal/csi-common/utils.go +++ b/internal/csi-common/utils.go @@ -156,13 +156,13 @@ func contextIDInjector(ctx context.Context, req interface{}, info *grpc.UnarySer } func logGRPC(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) { - klog.V(3).Infof(util.Log(ctx, "GRPC call: %s"), info.FullMethod) - klog.V(5).Infof(util.Log(ctx, "GRPC request: %s"), protosanitizer.StripSecrets(req)) + util.ExtendedLog(ctx, "GRPC call: %s", info.FullMethod) + util.TraceLog(ctx, "GRPC request: %s", protosanitizer.StripSecrets(req)) resp, err := handler(ctx, req) if err != nil { klog.Errorf(util.Log(ctx, "GRPC error: %v"), err) } else { - klog.V(5).Infof(util.Log(ctx, "GRPC response: %s"), protosanitizer.StripSecrets(resp)) + util.TraceLog(ctx, "GRPC response: %s", protosanitizer.StripSecrets(resp)) } return resp, err } diff --git a/internal/journal/omap.go b/internal/journal/omap.go index a3ce33aa8..f975a25ec 100644 --- a/internal/journal/omap.go +++ b/internal/journal/omap.go @@ -71,8 +71,7 @@ func getOMapValues( return nil, err } - klog.V(4).Infof( - util.Log(ctx, "got omap values: (pool=%q, namespace=%q, name=%q): %+v"), + util.DebugLog(ctx, "got omap values: (pool=%q, namespace=%q, name=%q): %+v", poolName, namespace, oid, results) return results, nil } @@ -98,8 +97,7 @@ func removeMapKeys( // the previous implementation of removing omap keys (via the cli) // treated failure to find the omap as a non-error. Do so here to // mimic the previous behavior. - klog.V(4).Infof( - util.Log(ctx, "when removing omap keys, omap not found (pool=%q, namespace=%q, name=%q): %+v"), + util.DebugLog(ctx, "when removing omap keys, omap not found (pool=%q, namespace=%q, name=%q): %+v", poolName, namespace, oid, keys) } else { klog.Errorf( @@ -108,8 +106,7 @@ func removeMapKeys( return err } } - klog.V(4).Infof( - util.Log(ctx, "removed omap keys (pool=%q, namespace=%q, name=%q): %+v"), + util.DebugLog(ctx, "removed omap keys (pool=%q, namespace=%q, name=%q): %+v", poolName, namespace, oid, keys) return nil } @@ -140,8 +137,7 @@ func setOMapKeys( poolName, namespace, oid, pairs, err) return err } - klog.V(4).Infof( - util.Log(ctx, "set omap keys (pool=%q, namespace=%q, name=%q): %+v)"), + util.DebugLog(ctx, "set omap keys (pool=%q, namespace=%q, name=%q): %+v)", poolName, namespace, oid, pairs) return nil } diff --git a/internal/journal/voljournal.go b/internal/journal/voljournal.go index 359a989e6..fdce3222f 100644 --- a/internal/journal/voljournal.go +++ b/internal/journal/voljournal.go @@ -449,7 +449,7 @@ func reserveOMapName(ctx context.Context, monitors string, cr *util.Credentials, if errors.As(err, &eoe) { attempt++ // try again with a different uuid, for maxAttempts tries - klog.V(4).Infof(util.Log(ctx, "uuid (%s) conflict detected, retrying (attempt %d of %d)"), + util.DebugLog(ctx, "uuid (%s) conflict detected, retrying (attempt %d of %d)", iterUUID, attempt, maxAttempts) continue } diff --git a/internal/liveness/liveness.go b/internal/liveness/liveness.go index 3cb08076d..45d30472b 100644 --- a/internal/liveness/liveness.go +++ b/internal/liveness/liveness.go @@ -42,7 +42,7 @@ func getLiveness(timeout time.Duration, csiConn *grpc.ClientConn) { ctx, cancel := context.WithTimeout(context.Background(), timeout) defer cancel() - klog.V(5).Info("Sending probe request to CSI driver") + util.TraceLogMsg("Sending probe request to CSI driver") ready, err := rpc.Probe(ctx, csiConn) if err != nil { liveness.Set(0) @@ -56,7 +56,7 @@ func getLiveness(timeout time.Duration, csiConn *grpc.ClientConn) { return } liveness.Set(1) - klog.V(3).Infof("Health check succeeded") + util.ExtendedLogMsg("Health check succeeded") } func recordLiveness(endpoint, drivername string, pollTime, timeout time.Duration) { @@ -84,7 +84,7 @@ func recordLiveness(endpoint, drivername string, pollTime, timeout time.Duration // Run starts liveness collection and prometheus endpoint func Run(conf *util.Config) { - klog.V(3).Infof("Liveness Running") + util.ExtendedLogMsg("Liveness Running") // start liveness collection go recordLiveness(conf.Endpoint, conf.DriverName, conf.PollTime, conf.PoolTimeout) diff --git a/internal/rbd/controllerserver.go b/internal/rbd/controllerserver.go index 0e774dee1..a64d17854 100644 --- a/internal/rbd/controllerserver.go +++ b/internal/rbd/controllerserver.go @@ -314,7 +314,7 @@ func (cs *ControllerServer) createVolumeFromSnapshot(ctx context.Context, cr *ut return err } - klog.V(4).Infof(util.Log(ctx, "create volume %s from snapshot %s"), rbdVol.RequestName, rbdSnap.RbdSnapName) + util.DebugLog(ctx, "create volume %s from snapshot %s", rbdVol.RequestName, rbdSnap.RbdSnapName) return nil } @@ -333,7 +333,7 @@ func (cs *ControllerServer) createBackingImage(ctx context.Context, cr *util.Cre if err != nil { return err } - klog.V(4).Infof(util.Log(ctx, "created volume %s from snapshot %s"), rbdVol.RequestName, rbdSnap.RbdSnapName) + util.DebugLog(ctx, "created volume %s from snapshot %s", rbdVol.RequestName, rbdSnap.RbdSnapName) } else { err = createImage(ctx, rbdVol, cr) if err != nil { @@ -342,7 +342,7 @@ func (cs *ControllerServer) createBackingImage(ctx context.Context, cr *util.Cre } } - klog.V(4).Infof(util.Log(ctx, "created volume %s backed by image %s"), rbdVol.RequestName, rbdVol.RbdImageName) + util.DebugLog(ctx, "created volume %s backed by image %s", rbdVol.RequestName, rbdVol.RbdImageName) defer func() { if err != nil { @@ -458,7 +458,7 @@ func (cs *ControllerServer) DeleteLegacyVolume(ctx context.Context, req *csi.Del // Update rbdImageName as the VolName when dealing with version 1 volumes rbdVol.RbdImageName = rbdVol.VolName - klog.V(4).Infof(util.Log(ctx, "deleting legacy volume %s"), rbdVol.VolName) + util.DebugLog(ctx, "deleting legacy volume %s", rbdVol.VolName) if err := deleteImage(ctx, rbdVol, cr); err != nil { // TODO: can we detect "already deleted" situations here and proceed? klog.Errorf(util.Log(ctx, "failed to delete legacy rbd image: %s/%s with error: %v"), rbdVol.Pool, rbdVol.VolName, err) @@ -516,7 +516,7 @@ func (cs *ControllerServer) DeleteVolume(ctx context.Context, req *csi.DeleteVol var eivi ErrInvalidVolID if errors.As(err, &eivi) { if isLegacyVolumeID(volumeID) { - klog.V(2).Infof(util.Log(ctx, "attempting deletion of potential legacy volume (%s)"), volumeID) + util.UsefulLog(ctx, "attempting deletion of potential legacy volume (%s)", volumeID) return cs.DeleteLegacyVolume(ctx, req, cr) } @@ -574,7 +574,7 @@ func (cs *ControllerServer) DeleteVolume(ctx context.Context, req *csi.DeleteVol } // Deleting rbd image - klog.V(4).Infof(util.Log(ctx, "deleting image %s"), rbdVol.RbdImageName) + util.DebugLog(ctx, "deleting image %s", rbdVol.RbdImageName) if err = deleteImage(ctx, rbdVol, cr); err != nil { klog.Errorf(util.Log(ctx, "failed to delete rbd image: %s with error: %v"), rbdVol, err) @@ -936,7 +936,7 @@ func (cs *ControllerServer) DeleteSnapshot(ctx context.Context, req *csi.DeleteS defer cs.SnapshotLocks.Release(rbdSnap.RequestName) // Deleting snapshot and cloned volume - klog.V(4).Infof(util.Log(ctx, "deleting cloned rbd volume %s"), rbdSnap.RbdSnapName) + util.DebugLog(ctx, "deleting cloned rbd volume %s", rbdSnap.RbdSnapName) rbdVol := generateVolFromSnap(rbdSnap) @@ -1034,7 +1034,7 @@ func (cs *ControllerServer) ControllerExpandVolume(ctx context.Context, req *csi // resize volume if required nodeExpansion := false if rbdVol.VolSize < volSize { - klog.V(4).Infof(util.Log(ctx, "rbd volume %s size is %v,resizing to %v"), rbdVol, rbdVol.VolSize, volSize) + util.DebugLog(ctx, "rbd volume %s size is %v,resizing to %v", rbdVol, rbdVol.VolSize, volSize) rbdVol.VolSize = volSize nodeExpansion = true err = resizeRBDImage(rbdVol, cr) diff --git a/internal/rbd/nodeserver.go b/internal/rbd/nodeserver.go index 5184ea100..85ab621ac 100644 --- a/internal/rbd/nodeserver.go +++ b/internal/rbd/nodeserver.go @@ -151,7 +151,7 @@ func (ns *NodeServer) NodeStageVolume(ctx context.Context, req *csi.NodeStageVol } if !isNotMnt { - klog.V(4).Infof(util.Log(ctx, "rbd: volume %s is already mounted to %s, skipping"), volID, stagingTargetPath) + util.DebugLog(ctx, "rbd: volume %s is already mounted to %s, skipping", volID, stagingTargetPath) return &csi.NodeStageVolumeResponse{}, nil } @@ -221,7 +221,7 @@ func (ns *NodeServer) NodeStageVolume(ctx context.Context, req *csi.NodeStageVol return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "rbd: successfully mounted volume %s to stagingTargetPath %s"), req.GetVolumeId(), stagingTargetPath) + util.DebugLog(ctx, "rbd: successfully mounted volume %s to stagingTargetPath %s", req.GetVolumeId(), stagingTargetPath) return &csi.NodeStageVolumeResponse{}, nil } @@ -249,7 +249,7 @@ func (ns *NodeServer) stageTransaction(ctx context.Context, req *csi.NodeStageVo // Allow image to be mounted on multiple nodes if it is ROX if req.VolumeCapability.AccessMode.Mode == csi.VolumeCapability_AccessMode_MULTI_NODE_READER_ONLY { - klog.V(3).Infof(util.Log(ctx, "setting disableInUseChecks on rbd volume to: %v"), req.GetVolumeId) + util.ExtendedLog(ctx, "setting disableInUseChecks on rbd volume to: %v", req.GetVolumeId) volOptions.DisableInUseChecks = true volOptions.readOnly = true } @@ -282,7 +282,7 @@ func (ns *NodeServer) stageTransaction(ctx context.Context, req *csi.NodeStageVo return transaction, err } transaction.devicePath = devicePath - klog.V(4).Infof(util.Log(ctx, "rbd image: %s/%s was successfully mapped at %s\n"), + util.DebugLog(ctx, "rbd image: %s/%s was successfully mapped at %s\n", req.GetVolumeId(), volOptions.Pool, devicePath) if volOptions.Encrypted { @@ -417,7 +417,7 @@ func (ns *NodeServer) NodePublishVolume(ctx context.Context, req *csi.NodePublis return nil, err } - klog.V(4).Infof(util.Log(ctx, "rbd: successfully mounted stagingPath %s to targetPath %s"), stagingPath, targetPath) + util.DebugLog(ctx, "rbd: successfully mounted stagingPath %s to targetPath %s", stagingPath, targetPath) return &csi.NodePublishVolumeResponse{}, nil } @@ -528,7 +528,7 @@ func (ns *NodeServer) mountVolume(ctx context.Context, stagingPath string, req * mountOptions = csicommon.ConstructMountOptions(mountOptions, req.GetVolumeCapability()) - klog.V(4).Infof(util.Log(ctx, "target %v\nisBlock %v\nfstype %v\nstagingPath %v\nreadonly %v\nmountflags %v\n"), + util.DebugLog(ctx, "target %v\nisBlock %v\nfstype %v\nstagingPath %v\nreadonly %v\nmountflags %v\n", targetPath, isBlock, fsType, stagingPath, readOnly, mountOptions) if readOnly { @@ -550,11 +550,11 @@ func (ns *NodeServer) createTargetMountPath(ctx context.Context, mountPath strin // #nosec pathFile, e := os.OpenFile(mountPath, os.O_CREATE|os.O_RDWR, 0750) if e != nil { - klog.V(4).Infof(util.Log(ctx, "Failed to create mountPath:%s with error: %v"), mountPath, err) + util.DebugLog(ctx, "Failed to create mountPath:%s with error: %v", mountPath, err) return notMnt, status.Error(codes.Internal, e.Error()) } if err = pathFile.Close(); err != nil { - klog.V(4).Infof(util.Log(ctx, "Failed to close mountPath:%s with error: %v"), mountPath, err) + util.DebugLog(ctx, "Failed to close mountPath:%s with error: %v", mountPath, err) return notMnt, status.Error(codes.Internal, err.Error()) } } else { @@ -591,7 +591,7 @@ func (ns *NodeServer) NodeUnpublishVolume(ctx context.Context, req *csi.NodeUnpu if err != nil { if os.IsNotExist(err) { // targetPath has already been deleted - klog.V(4).Infof(util.Log(ctx, "targetPath: %s has already been deleted"), targetPath) + util.DebugLog(ctx, "targetPath: %s has already been deleted", targetPath) return &csi.NodeUnpublishVolumeResponse{}, nil } return nil, status.Error(codes.NotFound, err.Error()) @@ -611,7 +611,7 @@ func (ns *NodeServer) NodeUnpublishVolume(ctx context.Context, req *csi.NodeUnpu return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "rbd: successfully unbound volume %s from %s"), req.GetVolumeId(), targetPath) + util.DebugLog(ctx, "rbd: successfully unbound volume %s from %s", req.GetVolumeId(), targetPath) return &csi.NodeUnpublishVolumeResponse{}, nil } @@ -659,7 +659,7 @@ func (ns *NodeServer) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstag // Unmounting the image err = ns.mounter.Unmount(stagingTargetPath) if err != nil { - klog.V(3).Infof(util.Log(ctx, "failed to unmount targetPath: %s with error: %v"), stagingTargetPath, err) + util.ExtendedLog(ctx, "failed to unmount targetPath: %s with error: %v", stagingTargetPath, err) return nil, status.Error(codes.Internal, err.Error()) } } @@ -676,7 +676,7 @@ func (ns *NodeServer) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstag imgInfo, err := lookupRBDImageMetadataStash(stagingParentPath) if err != nil { - klog.V(2).Infof(util.Log(ctx, "failed to find image metadata: %v"), err) + util.UsefulLog(ctx, "failed to find image metadata: %v", err) // It is an error if it was mounted, as we should have found the image metadata file with // no errors if !notMnt { @@ -701,7 +701,7 @@ func (ns *NodeServer) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstag return nil, status.Error(codes.Internal, err.Error()) } - klog.V(4).Infof(util.Log(ctx, "successfully unmounted volume (%s) from staging path (%s)"), + util.DebugLog(ctx, "successfully unmounted volume (%s) from staging path (%s)", req.GetVolumeId(), stagingTargetPath) if err = cleanupRBDImageMetadataStash(stagingParentPath); err != nil { @@ -888,7 +888,7 @@ func openEncryptedDevice(ctx context.Context, volOptions *rbdVolume, devicePath return devicePath, err } if isOpen { - klog.V(4).Infof(util.Log(ctx, "encrypted device is already open at %s"), mapperFilePath) + util.DebugLog(ctx, "encrypted device is already open at %s", mapperFilePath) } else { err = util.OpenEncryptedVolume(ctx, devicePath, mapperFile, passphrase) if err != nil { diff --git a/internal/rbd/rbd_attach.go b/internal/rbd/rbd_attach.go index f75eb76c8..f8e9ce2c1 100644 --- a/internal/rbd/rbd_attach.go +++ b/internal/rbd/rbd_attach.go @@ -161,15 +161,15 @@ func checkRbdNbdTools() bool { // try to load the module _, err = execCommand("modprobe", []string{moduleNbd}) if err != nil { - klog.V(3).Infof("rbd-nbd: nbd modprobe failed with error %v", err) + util.ExtendedLogMsg("rbd-nbd: nbd modprobe failed with error %v", err) return false } } if _, err := execCommand(rbdTonbd, []string{"--version"}); err != nil { - klog.V(3).Infof("rbd-nbd: running rbd-nbd --version failed with error %v", err) + util.ExtendedLogMsg("rbd-nbd: running rbd-nbd --version failed with error %v", err) return false } - klog.V(3).Infof("rbd-nbd tools were found.") + util.ExtendedLogMsg("rbd-nbd tools were found.") return true } @@ -205,7 +205,7 @@ func createPath(ctx context.Context, volOpt *rbdVolume, cr *util.Credentials) (s isNbd := false imagePath := volOpt.String() - klog.V(5).Infof(util.Log(ctx, "rbd: map mon %s"), volOpt.Monitors) + util.TraceLog(ctx, "rbd: map mon %s", volOpt.Monitors) // Map options mapOptions := []string{ @@ -255,7 +255,7 @@ func waitForrbdImage(ctx context.Context, backoff wait.Backoff, volOptions *rbdV return false, fmt.Errorf("fail to check rbd image status with: (%v), rbd output: (%s)", err, rbdOutput) } if (volOptions.DisableInUseChecks) && (used) { - klog.V(2).Info(util.Log(ctx, "valid multi-node attach requested, ignoring watcher in-use result")) + util.UsefulLog(ctx, "valid multi-node attach requested, ignoring watcher in-use result") return used, nil } return !used, nil @@ -316,7 +316,7 @@ func detachRBDImageOrDeviceSpec(ctx context.Context, imageOrDeviceSpec string, i (strings.Contains(string(output), fmt.Sprintf(rbdUnmapCmdkRbdMissingMap, imageOrDeviceSpec)) || strings.Contains(string(output), fmt.Sprintf(rbdUnmapCmdNbdMissingMap, imageOrDeviceSpec))) { // Devices found not to be mapped are treated as a successful detach - klog.V(5).Infof(util.Log(ctx, "image or device spec (%s) not mapped"), imageOrDeviceSpec) + util.TraceLog(ctx, "image or device spec (%s) not mapped", imageOrDeviceSpec) return nil } return fmt.Errorf("rbd: unmap for spec (%s) failed (%v): (%s)", imageOrDeviceSpec, err, string(output)) diff --git a/internal/rbd/rbd_journal.go b/internal/rbd/rbd_journal.go index ec1a2b522..1a0093c38 100644 --- a/internal/rbd/rbd_journal.go +++ b/internal/rbd/rbd_journal.go @@ -215,7 +215,7 @@ func checkSnapCloneExists(ctx context.Context, parentVol *rbdVolume, rbdSnap *rb return false, err } - klog.V(4).Infof(util.Log(ctx, "found existing image (%s) with name (%s) for request (%s)"), + util.DebugLog(ctx, "found existing image (%s) with name (%s) for request (%s)", rbdSnap.SnapID, rbdSnap.RbdSnapName, rbdSnap.RequestName) return true, nil } @@ -316,7 +316,7 @@ func (rv *rbdVolume) Exists(ctx context.Context) (bool, error) { return false, err } - klog.V(4).Infof(util.Log(ctx, "found existing volume (%s) with image name (%s) for request (%s)"), + util.DebugLog(ctx, "found existing volume (%s) with image name (%s) for request (%s)", rv.VolID, rv.RbdImageName, rv.RequestName) return true, nil @@ -353,7 +353,7 @@ func reserveSnap(ctx context.Context, rbdSnap *rbdSnapshot, rbdVol *rbdVolume, c return err } - klog.V(4).Infof(util.Log(ctx, "generated Volume ID (%s) and image name (%s) for request name (%s)"), + util.DebugLog(ctx, "generated Volume ID (%s) and image name (%s) for request name (%s)", rbdSnap.SnapID, rbdSnap.RbdSnapName, rbdSnap.RequestName) return nil @@ -431,7 +431,7 @@ func reserveVol(ctx context.Context, rbdVol *rbdVolume, rbdSnap *rbdSnapshot, cr return err } - klog.V(4).Infof(util.Log(ctx, "generated Volume ID (%s) and image name (%s) for request name (%s)"), + util.DebugLog(ctx, "generated Volume ID (%s) and image name (%s) for request name (%s)", rbdVol.VolID, rbdVol.RbdImageName, rbdVol.RequestName) return nil diff --git a/internal/rbd/rbd_util.go b/internal/rbd/rbd_util.go index 4ec3e915c..70ae87f96 100644 --- a/internal/rbd/rbd_util.go +++ b/internal/rbd/rbd_util.go @@ -194,7 +194,7 @@ func createImage(ctx context.Context, pOpts *rbdVolume, cr *util.Credentials) er return fmt.Errorf("failed to set data pool: %w", err) } } - klog.V(4).Infof(util.Log(ctx, logMsg), + util.DebugLog(ctx, logMsg, pOpts, volSzMiB, pOpts.imageFeatureSet.Names(), pOpts.Monitors) if pOpts.imageFeatureSet != 0 { @@ -285,7 +285,7 @@ func rbdStatus(ctx context.Context, pOpts *rbdVolume, cr *util.Credentials) (boo var output string var cmd []byte - klog.V(4).Infof(util.Log(ctx, "rbd: status %s using mon %s"), pOpts, pOpts.Monitors) + util.DebugLog(ctx, "rbd: status %s using mon %s", pOpts, pOpts.Monitors) args := []string{"status", pOpts.String(), "-m", pOpts.Monitors, "--id", cr.ID, "--keyfile=" + cr.KeyFile} cmd, err := execCommand("rbd", args) output = string(cmd) @@ -305,7 +305,7 @@ func rbdStatus(ctx context.Context, pOpts *rbdVolume, cr *util.Credentials) (boo } if strings.Contains(output, imageWatcherStr) { - klog.V(4).Infof(util.Log(ctx, "rbd: watchers on %s: %s"), pOpts, output) + util.DebugLog(ctx, "rbd: watchers on %s: %s", pOpts, output) return true, output, nil } klog.Warningf(util.Log(ctx, "rbd: no watchers on %s"), pOpts) @@ -319,7 +319,7 @@ func addRbdManagerTask(ctx context.Context, pOpts *rbdVolume, arg []string) (boo var output []byte args := []string{"rbd", "task", "add"} args = append(args, arg...) - klog.V(4).Infof(util.Log(ctx, "executing %v for image (%s) using mon %s, pool %s"), args, pOpts.RbdImageName, pOpts.Monitors, pOpts.Pool) + util.DebugLog(ctx, "executing %v for image (%s) using mon %s, pool %s", args, pOpts.RbdImageName, pOpts.Monitors, pOpts.Pool) supported := true output, err := execCommand("ceph", args) @@ -348,7 +348,7 @@ func deleteImage(ctx context.Context, pOpts *rbdVolume, cr *util.Credentials) er return err } - klog.V(4).Infof(util.Log(ctx, "rbd: delete %s using mon %s, pool %s"), image, pOpts.Monitors, pOpts.Pool) + util.DebugLog(ctx, "rbd: delete %s using mon %s, pool %s", image, pOpts.Monitors, pOpts.Pool) err = pOpts.openIoctx() if err != nil { @@ -803,7 +803,7 @@ func genVolFromVolumeOptions(ctx context.Context, volOptions, credentials map[st rbdVol.imageFeatureSet = librbd.FeatureSetFromNames(arr) } - klog.V(3).Infof(util.Log(ctx, "setting disableInUseChecks on rbd volume to: %v"), disableInUseChecks) + util.ExtendedLog(ctx, "setting disableInUseChecks on rbd volume to: %v", disableInUseChecks) rbdVol.DisableInUseChecks = disableInUseChecks rbdVol.Mounter, ok = volOptions["mounter"] @@ -860,7 +860,7 @@ func (rv *rbdVolume) hasSnapshotFeature() bool { } func (rv *rbdVolume) createSnapshot(ctx context.Context, pOpts *rbdSnapshot) error { - klog.V(4).Infof(util.Log(ctx, "rbd: snap create %s using mon %s"), pOpts, pOpts.Monitors) + util.DebugLog(ctx, "rbd: snap create %s using mon %s", pOpts, pOpts.Monitors) image, err := rv.open() if err != nil { return err @@ -872,7 +872,7 @@ func (rv *rbdVolume) createSnapshot(ctx context.Context, pOpts *rbdSnapshot) err } func (rv *rbdVolume) deleteSnapshot(ctx context.Context, pOpts *rbdSnapshot) error { - klog.V(4).Infof(util.Log(ctx, "rbd: snap rm %s using mon %s"), pOpts, pOpts.Monitors) + util.DebugLog(ctx, "rbd: snap rm %s using mon %s", pOpts, pOpts.Monitors) image, err := rv.open() if err != nil { return err @@ -893,7 +893,7 @@ func (rv *rbdVolume) deleteSnapshot(ctx context.Context, pOpts *rbdSnapshot) err func (rv *rbdVolume) cloneRbdImageFromSnapshot(ctx context.Context, pSnapOpts *rbdSnapshot) error { image := rv.RbdImageName var err error - klog.V(4).Infof(util.Log(ctx, "rbd: clone %s %s using mon %s"), pSnapOpts, image, rv.Monitors) + util.DebugLog(ctx, "rbd: clone %s %s using mon %s", pSnapOpts, image, rv.Monitors) options := librbd.NewRbdImageOptions() defer options.Destroy() @@ -1158,7 +1158,7 @@ func (rv *rbdVolume) checkRbdImageEncrypted(ctx context.Context) (string, error) } encrypted := strings.TrimSpace(value) - klog.V(4).Infof(util.Log(ctx, "image %s encrypted state metadata reports %q"), rv, encrypted) + util.DebugLog(ctx, "image %s encrypted state metadata reports %q", rv, encrypted) return encrypted, nil } diff --git a/internal/util/cachepersister.go b/internal/util/cachepersister.go index 7f4b520f9..6a27a7c8a 100644 --- a/internal/util/cachepersister.go +++ b/internal/util/cachepersister.go @@ -18,8 +18,6 @@ package util import ( "errors" - - klog "k8s.io/klog/v2" ) // ForAllFunc is a unary predicate for visiting all cache entries @@ -42,13 +40,13 @@ type CachePersister interface { // NewCachePersister returns CachePersister based on store func NewCachePersister(metadataStore, pluginPath string) (CachePersister, error) { if metadataStore == "k8s_configmap" { - klog.V(4).Infof("cache-perister: using kubernetes configmap as metadata cache persister") + DebugLogMsg("cache-perister: using kubernetes configmap as metadata cache persister") k8scm := &K8sCMCache{} k8scm.Client = NewK8sClient() k8scm.Namespace = GetK8sNamespace() return k8scm, nil } else if metadataStore == "node" { - klog.V(4).Infof("cache-persister: using node as metadata cache persister") + DebugLogMsg("cache-persister: using node as metadata cache persister") nc := &NodeCache{} nc.BasePath = pluginPath nc.CacheDir = "controller" diff --git a/internal/util/crypto.go b/internal/util/crypto.go index d4192e578..17f4b5a69 100644 --- a/internal/util/crypto.go +++ b/internal/util/crypto.go @@ -148,7 +148,7 @@ func GetCryptoPassphrase(ctx context.Context, volumeID string, kms EncryptionKMS return passphrase, nil } if _, ok := err.(MissingPassphrase); ok { - klog.V(4).Infof(Log(ctx, "Encryption passphrase is missing for %s. Generating a new one"), + DebugLog(ctx, "Encryption passphrase is missing for %s. Generating a new one", volumeID) passphrase, err = generateNewEncryptionPassphrase() if err != nil { @@ -183,7 +183,7 @@ func VolumeMapper(volumeID string) (mapperFile, mapperFilePath string) { // EncryptVolume encrypts provided device with LUKS func EncryptVolume(ctx context.Context, devicePath, passphrase string) error { - klog.V(4).Infof(Log(ctx, "Encrypting device %s with LUKS"), devicePath) + DebugLog(ctx, "Encrypting device %s with LUKS", devicePath) if _, _, err := LuksFormat(devicePath, passphrase); err != nil { return fmt.Errorf("failed to encrypt device %s with LUKS: %w", devicePath, err) } @@ -192,14 +192,14 @@ func EncryptVolume(ctx context.Context, devicePath, passphrase string) error { // OpenEncryptedVolume opens volume so that it can be used by the client func OpenEncryptedVolume(ctx context.Context, devicePath, mapperFile, passphrase string) error { - klog.V(4).Infof(Log(ctx, "Opening device %s with LUKS on %s"), devicePath, mapperFile) + DebugLog(ctx, "Opening device %s with LUKS on %s", devicePath, mapperFile) _, _, err := LuksOpen(devicePath, mapperFile, passphrase) return err } // CloseEncryptedVolume closes encrypted volume so it can be detached func CloseEncryptedVolume(ctx context.Context, mapperFile string) error { - klog.V(4).Infof(Log(ctx, "Closing LUKS device %s"), mapperFile) + DebugLog(ctx, "Closing LUKS device %s", mapperFile) _, _, err := LuksClose(mapperFile) return err } @@ -220,7 +220,7 @@ func DeviceEncryptionStatus(ctx context.Context, devicePath string) (mappedDevic mapPath := strings.TrimPrefix(devicePath, mapperFilePathPrefix+"/") stdout, _, err := LuksStatus(mapPath) if err != nil { - klog.V(4).Infof(Log(ctx, "device %s is not an active LUKS device: %v"), devicePath, err) + DebugLog(ctx, "device %s is not an active LUKS device: %v", devicePath, err) return devicePath, "", nil } lines := strings.Split(string(stdout), "\n") diff --git a/internal/util/k8scmcache.go b/internal/util/k8scmcache.go index 7f25bfc19..6c2a03b8e 100644 --- a/internal/util/k8scmcache.go +++ b/internal/util/k8scmcache.go @@ -122,7 +122,7 @@ func (k8scm *K8sCMCache) ForAll(pattern string, destObj interface{}, f ForAllFun func (k8scm *K8sCMCache) Create(identifier string, data interface{}) error { cm, err := k8scm.getMetadataCM(identifier) if cm != nil && err == nil { - klog.V(4).Infof("k8s-cm-cache: configmap %s already exists, skipping configmap creation", identifier) + DebugLogMsg("k8s-cm-cache: configmap %s already exists, skipping configmap creation", identifier) return nil } dataJSON, err := json.Marshal(data) @@ -144,13 +144,13 @@ func (k8scm *K8sCMCache) Create(identifier string, data interface{}) error { _, err = k8scm.Client.CoreV1().ConfigMaps(k8scm.Namespace).Create(context.TODO(), cm, metav1.CreateOptions{}) if err != nil { if apierrs.IsAlreadyExists(err) { - klog.V(4).Infof("k8s-cm-cache: configmap %s already exists", identifier) + DebugLogMsg("k8s-cm-cache: configmap %s already exists", identifier) return nil } return fmt.Errorf("k8s-cm-cache: couldn't persist %s metadata as configmap: %w", identifier, err) } - klog.V(4).Infof("k8s-cm-cache: configmap %s successfully created", identifier) + DebugLogMsg("k8s-cm-cache: configmap %s successfully created", identifier) return nil } @@ -176,12 +176,12 @@ func (k8scm *K8sCMCache) Delete(identifier string) error { err := k8scm.Client.CoreV1().ConfigMaps(k8scm.Namespace).Delete(context.TODO(), identifier, metav1.DeleteOptions{}) if err != nil { if apierrs.IsNotFound(err) { - klog.V(4).Infof("k8s-cm-cache: cannot delete missing metadata configmap %s, assuming it's already deleted", identifier) + DebugLogMsg("k8s-cm-cache: cannot delete missing metadata configmap %s, assuming it's already deleted", identifier) return nil } return fmt.Errorf("k8s-cm-cache: couldn't delete metadata configmap %s: %w", identifier, err) } - klog.V(4).Infof("k8s-cm-cache: successfully deleted metadata configmap %s", identifier) + DebugLogMsg("k8s-cm-cache: successfully deleted metadata configmap %s", identifier) return nil } diff --git a/internal/util/nodecache.go b/internal/util/nodecache.go index fca02f169..3c5c588c2 100644 --- a/internal/util/nodecache.go +++ b/internal/util/nodecache.go @@ -86,7 +86,7 @@ func decodeObj(fpath, pattern string, file os.FileInfo, destObj interface{}) err // #nosec fp, err := os.Open(path.Join(fpath, file.Name())) if err != nil { - klog.V(4).Infof("node-cache: open file: %s err %v", file.Name(), err) + DebugLogMsg("node-cache: open file: %s err %v", file.Name(), err) return errDec } decoder := json.NewDecoder(fp) @@ -117,7 +117,7 @@ func (nc *NodeCache) Create(identifier string, data interface{}) error { if err = encoder.Encode(data); err != nil { return fmt.Errorf("node-cache: failed to encode metadata for file: %s: %w", file, err) } - klog.V(4).Infof("node-cache: successfully saved metadata into file: %s\n", file) + DebugLogMsg("node-cache: successfully saved metadata into file: %s\n", file) return nil } @@ -154,12 +154,12 @@ func (nc *NodeCache) Delete(identifier string) error { err := os.Remove(file) if err != nil { if os.IsNotExist(err) { - klog.V(4).Infof("node-cache: cannot delete missing metadata storage file %s, assuming it's already deleted", file) + DebugLogMsg("node-cache: cannot delete missing metadata storage file %s, assuming it's already deleted", file) return nil } return fmt.Errorf("node-cache: error removing file %s: %w", file, err) } - klog.V(4).Infof("node-cache: successfully deleted metadata storage file at: %+v\n", file) + DebugLogMsg("node-cache: successfully deleted metadata storage file at: %+v\n", file) return nil } diff --git a/internal/util/util.go b/internal/util/util.go index 775ebe36f..26e6e170f 100644 --- a/internal/util/util.go +++ b/internal/util/util.go @@ -36,6 +36,15 @@ import ( "k8s.io/utils/mount" ) +// enum defining logging levels. +const ( + Default klog.Level = iota + 1 + Useful + Extended + Debug + Trace +) + // RoundOffVolSize rounds up given quantity upto chunks of MiB/GiB func RoundOffVolSize(size int64) int64 { size = RoundOffBytes(size) @@ -337,3 +346,75 @@ func contains(s []string, key string) bool { return false } + +// DefaultLog helps in logging with klog.level 1 +func DefaultLog(message string, args ...interface{}) { + logMessage := fmt.Sprintf(message, args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Default).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// UsefulLog helps in logging with klog.level 2 +func UsefulLog(ctx context.Context, message string, args ...interface{}) { + logMessage := fmt.Sprintf(Log(ctx, message), args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Useful).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// ExtendedLogMsg helps in logging a message with klog.level 3 +func ExtendedLogMsg(message string, args ...interface{}) { + logMessage := fmt.Sprintf(message, args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Extended).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// ExtendedLog helps in logging with klog.level 3 +func ExtendedLog(ctx context.Context, message string, args ...interface{}) { + logMessage := fmt.Sprintf(Log(ctx, message), args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Extended).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// DebugLogMsg helps in logging a message with klog.level 4 +func DebugLogMsg(message string, args ...interface{}) { + logMessage := fmt.Sprintf(message, args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Debug).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// DebugLog helps in logging with klog.level 4 +func DebugLog(ctx context.Context, message string, args ...interface{}) { + logMessage := fmt.Sprintf(Log(ctx, message), args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Debug).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// TraceLogMsg helps in logging a message with klog.level 5 +func TraceLogMsg(message string, args ...interface{}) { + logMessage := fmt.Sprintf(message, args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Trace).Enabled() { + klog.InfoDepth(1, logMessage) + } +} + +// TraceLog helps in logging with klog.level 5 +func TraceLog(ctx context.Context, message string, args ...interface{}) { + logMessage := fmt.Sprintf(Log(ctx, message), args...) + // If logging is disabled, don't evaluate the arguments + if klog.V(Trace).Enabled() { + klog.InfoDepth(1, logMessage) + } +}