From 9d1fbe5a07ebe2186603adbc0d5c6227fb4398f4 Mon Sep 17 00:00:00 2001 From: Michael Weibel Date: Wed, 27 May 2026 11:30:43 +0200 Subject: [PATCH] fix(node): give every gRPC handler a request-scoped logger MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The node-service RPCs previously logged with the package-level default logger and ad-hoc field names, so the same volume_id appeared under different keys (sometimes "volume_id", sometimes "device_path") and many lines landed without enough context to correlate with kubelet's view. Build a single *logrus.Entry at the top of each handler with the canonical request fields (volume_id, staging_target_path, target_path, …) and thread it through the helpers. Additionally, fixes two instances of using error equality check instead of errors.Is. --- driver/driver.go | 2 +- driver/driver_test.go | 14 ++-- driver/mounter.go | 64 +++++++++--------- driver/node.go | 150 +++++++++++++++++++++++------------------- 4 files changed, 122 insertions(+), 108 deletions(-) diff --git a/driver/driver.go b/driver/driver.go index 36a6672c..683befe6 100644 --- a/driver/driver.go +++ b/driver/driver.go @@ -115,7 +115,7 @@ func NewDriver(ep, token, urlstr string, logLevel logrus.Level) (*Driver, error) serverId: serverId, zone: zone, cloudscaleClient: cloudscaleClient, - mounter: newMounter(log), + mounter: newMounter(), log: log, volumeLocks: NewVolumeLocks(), }, nil diff --git a/driver/driver_test.go b/driver/driver_test.go index e1af211c..78d6f14c 100644 --- a/driver/driver_test.go +++ b/driver/driver_test.go @@ -125,18 +125,18 @@ type fakeMounter struct { mu sync.RWMutex } -func (f *fakeMounter) Format(source string, fsType string, luksContext LuksContext) error { +func (f *fakeMounter) Format(source, fsType string, luksContext LuksContext, log *logrus.Entry) error { return nil } -func (f *fakeMounter) Mount(source string, target string, fsType string, luksContext LuksContext, options ...string) error { +func (f *fakeMounter) Mount(source, target, fsType string, luksContext LuksContext, log *logrus.Entry, options ...string) error { f.mu.Lock() defer f.mu.Unlock() f.mounted[target] = source return nil } -func (f *fakeMounter) Unmount(target string, luksContext LuksContext) error { +func (f *fakeMounter) Unmount(target string, luksContext LuksContext, log *logrus.Entry) error { f.mu.Lock() defer f.mu.Unlock() delete(f.mounted, target) @@ -153,14 +153,14 @@ func (f *fakeMounter) GetDeviceName(_ mount.Interface, mountPath string) (string return "", nil } -func (f *fakeMounter) FindAbsoluteDeviceByIDPath(volumeName string) (string, error) { +func (f *fakeMounter) FindAbsoluteDeviceByIDPath(volumeName string, log *logrus.Entry) (string, error) { return "/dev/sdb", nil } -func (f *fakeMounter) IsFormatted(source string, luksContext LuksContext) (bool, error) { +func (f *fakeMounter) IsFormatted(source string, luksContext LuksContext, log *logrus.Entry) (bool, error) { return true, nil } -func (f *fakeMounter) IsMounted(target string) (bool, error) { +func (f *fakeMounter) IsMounted(target string, log *logrus.Entry) (bool, error) { f.mu.RLock() defer f.mu.RUnlock() _, ok := f.mounted[target] @@ -168,7 +168,7 @@ func (f *fakeMounter) IsMounted(target string) (bool, error) { } func (f *fakeMounter) checkMountPath(path string) (sanity.PathKind, error) { - isMounted, err := f.IsMounted(path) + isMounted, err := f.IsMounted(path, nil) if err != nil { return "", err } diff --git a/driver/mounter.go b/driver/mounter.go index 12782336..815cbfcd 100644 --- a/driver/mounter.go +++ b/driver/mounter.go @@ -69,22 +69,22 @@ type volumeStatistics struct { // more than just mounting functionality by now. type Mounter interface { // Format formats the source with the given filesystem type - Format(source, fsType string, luksContext LuksContext) error + Format(source, fsType string, luksContext LuksContext, log *logrus.Entry) error // Mount mounts source to target with the given fstype and options. - Mount(source, target, fsType string, luksContext LuksContext, options ...string) error + Mount(source, target, fsType string, luksContext LuksContext, log *logrus.Entry, options ...string) error // Unmount unmounts the given target - Unmount(target string, luksContext LuksContext) error + Unmount(target string, luksContext LuksContext, log *logrus.Entry) error // IsFormatted checks whether the source device is formatted or not. It // returns true if the source device is already formatted. - IsFormatted(source string, luksContext LuksContext) (bool, error) + IsFormatted(source string, luksContext LuksContext, log *logrus.Entry) (bool, error) // IsMounted checks whether the target path is a correct mount (i.e: // propagated). It returns true if it's mounted. An error is returned in // case of system errors or if it's mounted incorrectly. - IsMounted(target string) (bool, error) + IsMounted(target string, log *logrus.Entry) (bool, error) // Used to find a path in /dev/disk/by-id with a serial that we have from // the cloudscale API. @@ -99,7 +99,7 @@ type Mounter interface { GetDeviceName(mounter mount.Interface, mountPath string) (string, error) - FindAbsoluteDeviceByIDPath(volumeName string) (string, error) + FindAbsoluteDeviceByIDPath(volumeName string, log *logrus.Entry) (string, error) HasRequiredSize(log *logrus.Entry, path string, requiredSize int64) (bool, error) } @@ -107,12 +107,11 @@ type Mounter interface { // architecture specific code in the future, such as mounter_darwin.go, // mounter_linux.go, etc.. type mounter struct { - log *logrus.Entry kMounter *mount.SafeFormatAndMount } // newMounter returns a new mounter instance -func newMounter(log *logrus.Entry) *mounter { +func newMounter() *mounter { kMounter := &mount.SafeFormatAndMount{ Interface: mount.New(""), Exec: kexec.New(), @@ -120,16 +119,15 @@ func newMounter(log *logrus.Entry) *mounter { return &mounter{ kMounter: kMounter, - log: log, } } -func (m *mounter) Format(source, fsType string, luksContext LuksContext) error { +func (m *mounter) Format(source, fsType string, luksContext LuksContext, log *logrus.Entry) error { mkfsCmd := fmt.Sprintf("mkfs.%s", fsType) _, err := exec.LookPath(mkfsCmd) if err != nil { - if err == exec.ErrNotFound { + if errors.Is(err, exec.ErrNotFound) { return fmt.Errorf("%q executable not found in $PATH", mkfsCmd) } return err @@ -155,7 +153,7 @@ func (m *mounter) Format(source, fsType string, luksContext LuksContext) error { } if !luksContext.EncryptionEnabled { - m.log.WithFields(logrus.Fields{ + log.WithFields(logrus.Fields{ "cmd": mkfsCmd, "args": mkfsArgs, }).Info("executing format command") @@ -172,7 +170,7 @@ func (m *mounter) Format(source, fsType string, luksContext LuksContext) error { if err != nil { return err } - err = luksFormat(source, mkfsCmd, mkfsArgs, luksContext, m.log) + err = luksFormat(source, mkfsCmd, mkfsArgs, luksContext, log) if err != nil { return err } @@ -180,7 +178,7 @@ func (m *mounter) Format(source, fsType string, luksContext LuksContext) error { } } -func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, options ...string) error { +func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, log *logrus.Entry, options ...string) error { if source == "" { return errors.New("source is not specified for mounting the volume") } @@ -203,7 +201,7 @@ func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, return fmt.Errorf("failed to create target file for raw block bind mount: %v", err) } if err := file.Close(); err != nil { - m.log.WithFields(logrus.Fields{"target": target}).Error("failed to close file handle") + log.WithFields(logrus.Fields{"target": target}).Error("failed to close file handle") } } else { // create target, os.Mkdirall is noop if directory exists @@ -214,9 +212,9 @@ func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, } if luksContext.EncryptionEnabled && luksContext.VolumeLifecycle == VolumeLifecycleNodeStageVolume { - luksSource, err := luksPrepareMount(source, luksContext, m.log) + luksSource, err := luksPrepareMount(source, luksContext, log) if err != nil { - m.log.WithFields(logrus.Fields{ + log.WithFields(logrus.Fields{ "error": err.Error(), "volume": luksContext.VolumeName, }).Error("failed to prepare luks volume for mounting") @@ -226,10 +224,10 @@ func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, source = luksSource } - if m.log.Logger.IsLevelEnabled(logrus.DebugLevel) { + if log.Logger.IsLevelEnabled(logrus.DebugLevel) { resolvedSource, resolveErr := filepath.EvalSymlinks(source) if resolveErr != nil { - m.log.WithFields(logrus.Fields{ + log.WithFields(logrus.Fields{ "source": source, "target": target, "fs_type": fsType, @@ -237,7 +235,7 @@ func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, "resolve_error": resolveErr, }).Debug("Mount: failed to resolve source symlink") } else { - m.log.WithFields(logrus.Fields{ + log.WithFields(logrus.Fields{ "source": source, "resolved_source": resolvedSource, "target": target, @@ -247,7 +245,7 @@ func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, } } - m.log.WithFields(logrus.Fields{ + log.WithFields(logrus.Fields{ "source": source, "target": target, "options": options, @@ -260,7 +258,7 @@ func (m *mounter) Mount(source, target, fsType string, luksContext LuksContext, return nil } -func (m *mounter) Unmount(target string, luksContext LuksContext) error { +func (m *mounter) Unmount(target string, luksContext LuksContext, log *logrus.Entry) error { if target == "" { return errors.New("target is not specified for unmounting the volume") } @@ -286,7 +284,7 @@ func (m *mounter) Unmount(target string, luksContext LuksContext) error { return err } if isLuksMapping { - err := luksClose(mappingName, m.log) + err := luksClose(mappingName, log) if err != nil { return err } @@ -301,7 +299,7 @@ func (m *mounter) Unmount(target string, luksContext LuksContext) error { func getMountSources(target string) ([]string, error) { _, err := exec.LookPath("findmnt") if err != nil { - if err == exec.ErrNotFound { + if errors.Is(err, exec.ErrNotFound) { return nil, fmt.Errorf("%q executable not found in $PATH", "findmnt") } return nil, err @@ -318,12 +316,12 @@ func getMountSources(target string) ([]string, error) { return strings.Split(string(out), "\n"), nil } -func (m *mounter) IsFormatted(source string, luksContext LuksContext) (bool, error) { +func (m *mounter) IsFormatted(source string, luksContext LuksContext, log *logrus.Entry) (bool, error) { if !luksContext.EncryptionEnabled { - return isVolumeFormatted(source, m.log) + return isVolumeFormatted(source, log) } - formatted, err := isLuksVolumeFormatted(source, luksContext, m.log) + formatted, err := isLuksVolumeFormatted(source, luksContext, log) if err != nil { return false, err } @@ -338,7 +336,7 @@ func isVolumeFormatted(source string, log *logrus.Entry) (bool, error) { blkidCmd := "blkid" _, err := exec.LookPath(blkidCmd) if err != nil { - if err == exec.ErrNotFound { + if errors.Is(err, exec.ErrNotFound) { return false, fmt.Errorf("%q executable not found in $PATH", blkidCmd) } return false, err @@ -371,7 +369,7 @@ func isVolumeFormatted(source string, log *logrus.Entry) (bool, error) { return true, nil } -func (m *mounter) IsMounted(target string) (bool, error) { +func (m *mounter) IsMounted(target string, log *logrus.Entry) (bool, error) { if target == "" { return false, errors.New("target is not specified for checking the mount") } @@ -379,7 +377,7 @@ func (m *mounter) IsMounted(target string) (bool, error) { findmntCmd := "findmnt" _, err := exec.LookPath(findmntCmd) if err != nil { - if err == exec.ErrNotFound { + if errors.Is(err, exec.ErrNotFound) { return false, fmt.Errorf("%q executable not found in $PATH", findmntCmd) } return false, err @@ -387,7 +385,7 @@ func (m *mounter) IsMounted(target string) (bool, error) { findmntArgs := []string{"-o", "TARGET,PROPAGATION,FSTYPE,OPTIONS", "-M", target, "-J"} - m.log.WithFields(logrus.Fields{ + log.WithFields(logrus.Fields{ "cmd": findmntCmd, "args": findmntArgs, }).Info("checking if target is mounted") @@ -618,8 +616,8 @@ func (m *mounter) GetDeviceName(mounter mount.Interface, mountPath string) (stri } // FindAbsoluteDeviceByIDPath follows the /dev/disk/by-id symlink to find the absolute path of a device -func (m *mounter) FindAbsoluteDeviceByIDPath(volumeName string) (string, error) { - path := guessDiskIDPathByVolumeID(volumeName, m.log) +func (m *mounter) FindAbsoluteDeviceByIDPath(volumeName string, log *logrus.Entry) (string, error) { + path := guessDiskIDPathByVolumeID(volumeName, log) if path == "" { return "", fmt.Errorf("could not find device-path for volume: %s", volumeName) } diff --git a/driver/node.go b/driver/node.go index 167c5278..c566fe35 100644 --- a/driver/node.go +++ b/driver/node.go @@ -48,7 +48,6 @@ const ( // volume to a staging path. Once mounted, NodePublishVolume will make sure to // mount it to the appropriate path func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRequest) (*csi.NodeStageVolumeResponse, error) { - d.log.Info("node stage volume called") if req.VolumeId == "" { return nil, status.Error(codes.InvalidArgument, "NodeStageVolume Volume ID must be provided") } @@ -61,6 +60,15 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe return nil, status.Error(codes.InvalidArgument, "NodeStageVolume Volume Capability must be provided") } + ll := d.log.WithFields(logrus.Fields{ + "volume_id": req.VolumeId, + "staging_target_path": req.StagingTargetPath, + "method": "node_stage_volume", + "volume_context": req.VolumeContext, + "publish_context": req.PublishContext, + }) + ll.Info("node stage volume called") + if acquired := d.volumeLocks.TryAcquire(req.VolumeId); !acquired { return nil, status.Errorf(codes.Aborted, "an operation with the given Volume ID %s already exists", req.VolumeId) } @@ -69,15 +77,15 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe // Apparently sometimes we need to call udevadm trigger to get the volume // properly registered in /dev/disk. More information can be found here: // https://github.com/cloudscale-ch/csi-cloudscale/issues/9 - source, err := d.mounter.FinalizeVolumeAttachmentAndFindPath(d.log.WithFields(logrus.Fields{"volume_id": req.VolumeId}), req.VolumeId) + source, err := d.mounter.FinalizeVolumeAttachmentAndFindPath(ll, req.VolumeId) if err != nil { return nil, err } - d.log.WithFields(logrus.Fields{ - "volume_id": req.VolumeId, - "device_path": source, - }).Info("successfully found attached volume_id at device_path") + ll = ll.WithFields(logrus.Fields{ + "source": source, + }) + ll.Info("resolved volume device path") publishContext := req.GetPublishContext() if publishContext == nil { @@ -108,28 +116,22 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe fsType = mnt.FsType } - ll := d.log.WithFields(logrus.Fields{ - "volume_id": req.VolumeId, - "volume_mode": volumeModeFilesystem, - "volume_name": volumeName, - "volume_context": req.VolumeContext, - "publish_context": req.PublishContext, - "staging_target_path": req.StagingTargetPath, - "source": source, - "fs_type": fsType, - "mount_options": options, - "method": "node_stage_volume", - "luks_encrypted": luksContext.EncryptionEnabled, + ll = ll.WithFields(logrus.Fields{ + "volume_mode": volumeModeFilesystem, + "volume_name": volumeName, + "fs_type": fsType, + "mount_options": options, + "luks_encrypted": luksContext.EncryptionEnabled, }) - formatted, err := d.mounter.IsFormatted(source, luksContext) + formatted, err := d.mounter.IsFormatted(source, luksContext, ll) if err != nil { return nil, err } if !formatted { ll.Info("formatting the volume for staging") - if err := d.mounter.Format(source, fsType, luksContext); err != nil { + if err := d.mounter.Format(source, fsType, luksContext, ll); err != nil { return nil, status.Error(codes.Internal, err.Error()) } } else { @@ -138,7 +140,7 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe ll.Info("checking if stagingTargetPath is already mounted") - mounted, err := d.mounter.IsMounted(stagingTargetPath) + mounted, err := d.mounter.IsMounted(stagingTargetPath, ll) if err != nil { ll.WithError(err).Error("unable to check if already mounted") return nil, err @@ -146,7 +148,7 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe if !mounted { ll.Info("not mounted yet, mounting the volume for staging") - if err := d.mounter.Mount(source, stagingTargetPath, fsType, luksContext, options...); err != nil { + if err := d.mounter.Mount(source, stagingTargetPath, fsType, luksContext, ll, options...); err != nil { return nil, status.Error(codes.Internal, err.Error()) } } else { @@ -167,6 +169,10 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe return nil, status.Errorf(codes.Internal, "NodeStageVolume unable to get device path for %q: %v", stagingTargetPath, err) } + ll = ll.WithFields(logrus.Fields{ + "device_path": devicePath, + }) + // If the staged device is a LUKS mapping, grow the LUKS container first so // the filesystem can see the larger size. isLuks, _, err := isLuksMapping(devicePath) @@ -174,7 +180,7 @@ func (d *Driver) NodeStageVolume(ctx context.Context, req *csi.NodeStageVolumeRe return nil, status.Errorf(codes.Internal, "NodeStageVolume unable to test if volume at %q is encrypted with LUKS: %v", devicePath, err) } if isLuks { - ll.WithField("device_path", devicePath).Info("resizing LUKS container before filesystem resize") + ll.Info("resizing LUKS container before filesystem resize") if err := luksResize(devicePath); err != nil { return nil, status.Errorf(codes.Internal, "failed to resize LUKS container on %s: %v", devicePath, err) } @@ -220,14 +226,14 @@ func (d *Driver) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstageVolu }) ll.Info("node unstage volume called") - mounted, err := d.mounter.IsMounted(req.StagingTargetPath) + mounted, err := d.mounter.IsMounted(req.StagingTargetPath, ll) if err != nil { return nil, err } if mounted { ll.Info("unmounting the staging target path") - err := d.mounter.Unmount(req.StagingTargetPath, luksContext) + err := d.mounter.Unmount(req.StagingTargetPath, luksContext, ll) if err != nil { return nil, err } @@ -241,7 +247,6 @@ func (d *Driver) NodeUnstageVolume(ctx context.Context, req *csi.NodeUnstageVolu // NodePublishVolume mounts the volume mounted to the staging path to the target path func (d *Driver) NodePublishVolume(ctx context.Context, req *csi.NodePublishVolumeRequest) (*csi.NodePublishVolumeResponse, error) { - d.log.Info("node publish volume called") if req.VolumeId == "" { return nil, status.Error(codes.InvalidArgument, "NodePublishVolume Volume ID must be provided") } @@ -258,6 +263,14 @@ func (d *Driver) NodePublishVolume(ctx context.Context, req *csi.NodePublishVolu return nil, status.Error(codes.InvalidArgument, "NodePublishVolume Volume Capability must be provided") } + ll := d.log.WithFields(logrus.Fields{ + "volume_id": req.VolumeId, + "staging_target_path": req.StagingTargetPath, + "target_path": req.TargetPath, + "method": "node_publish_volume", + }) + ll.Info("node publish volume called") + if acquired := d.volumeLocks.TryAcquire(req.VolumeId); !acquired { return nil, status.Errorf(codes.Aborted, "an operation with the given Volume ID %s already exists", req.VolumeId) } @@ -269,12 +282,8 @@ func (d *Driver) NodePublishVolume(ctx context.Context, req *csi.NodePublishVolu } luksContext := getLuksContext(req.Secrets, publishContext, VolumeLifecycleNodePublishVolume) - ll := d.log.WithFields(logrus.Fields{ - "volume_id": req.VolumeId, - "staging_target_path": req.StagingTargetPath, - "target_path": req.TargetPath, - "method": "node_publish_volume", - "luks_encrypted": luksContext.EncryptionEnabled, + ll = ll.WithFields(logrus.Fields{ + "luks_encrypted": luksContext.EncryptionEnabled, }) options := []string{"bind"} @@ -296,7 +305,7 @@ func (d *Driver) NodePublishVolume(ctx context.Context, req *csi.NodePublishVolu return nil, err } - logrus.Info("bind mounting the volume is finished") + ll.Info("bind mounting the volume is finished") return &csi.NodePublishVolumeResponse{}, nil } @@ -318,13 +327,14 @@ func (d *Driver) NodeUnpublishVolume(ctx context.Context, req *csi.NodeUnpublish luksContext := LuksContext{VolumeLifecycle: VolumeLifecycleNodeUnpublishVolume} ll := d.log.WithFields(logrus.Fields{ - "volume_id": req.VolumeId, - "target_path": req.TargetPath, - "method": "node_unpublish_volume", + "volume_id": req.VolumeId, + "target_path": req.TargetPath, + "method": "node_unpublish_volume", + "luks_encrypted": luksContext.EncryptionEnabled, }) ll.Info("node unpublish volume called") - err := d.mounter.Unmount(req.TargetPath, luksContext) + err := d.mounter.Unmount(req.TargetPath, luksContext, ll) if err != nil { return nil, err } @@ -402,8 +412,6 @@ func (d *Driver) NodeGetInfo(ctx context.Context, req *csi.NodeGetInfoRequest) ( // NodeGetVolumeStats returns the volume capacity statistics available for the // the given volume. func (d *Driver) NodeGetVolumeStats(ctx context.Context, req *csi.NodeGetVolumeStatsRequest) (*csi.NodeGetVolumeStatsResponse, error) { - ll := d.log.WithField("method", "node_get_volume_stats") - ll.Info("node get volume stats called") if req.VolumeId == "" { return nil, status.Error(codes.InvalidArgument, "NodeGetVolumeStats Volume ID must be provided") @@ -414,7 +422,15 @@ func (d *Driver) NodeGetVolumeStats(ctx context.Context, req *csi.NodeGetVolumeS return nil, status.Error(codes.InvalidArgument, "NodeGetVolumeStats Volume Path must be provided") } - mounted, err := d.mounter.IsMounted(volumePath) + ll := d.log.WithFields(logrus.Fields{ + "method": "node_get_volume_stats", + "volume_path": volumePath, + "volume_id": req.VolumeId, + "staging_target_path": req.StagingTargetPath, + }) + ll.Info("node get volume stats called") + + mounted, err := d.mounter.IsMounted(volumePath, ll) if err != nil { return nil, status.Errorf(codes.Internal, "failed to check if volume path %q is mounted: %s", volumePath, err) } @@ -462,13 +478,13 @@ func (d *Driver) NodeGetVolumeStats(ctx context.Context, req *csi.NodeGetVolumeS return &csi.NodeGetVolumeStatsResponse{ Usage: []*csi.VolumeUsage{ - &csi.VolumeUsage{ + { Available: stats.availableBytes, Total: stats.totalBytes, Used: stats.usedBytes, Unit: csi.VolumeUsage_BYTES, }, - &csi.VolumeUsage{ + { Available: stats.availableInodes, Total: stats.totalInodes, Used: stats.usedInodes, @@ -484,32 +500,34 @@ func (d *Driver) NodeExpandVolume(ctx context.Context, req *csi.NodeExpandVolume return nil, status.Error(codes.InvalidArgument, "NodeExpandVolume volume ID not provided") } - source, err := d.mounter.FindAbsoluteDeviceByIDPath(volumeID) - if err != nil { - return nil, status.Errorf(codes.Internal, "Failed to find device path for volume %s. %v", volumeID, err) - } - volumePath := req.VolumePath if len(volumePath) == 0 { return nil, status.Error(codes.InvalidArgument, "NodeExpandVolume volume path not provided") } - log := d.log.WithFields(logrus.Fields{ + ll := d.log.WithFields(logrus.Fields{ "volume_id": req.VolumeId, "volume_path": req.VolumePath, "method": "node_expand_volume", }) - log.Info("node expand volume called") + ll.Info("node expand volume called") + + source, err := d.mounter.FindAbsoluteDeviceByIDPath(volumeID, ll) + if err != nil { + return nil, status.Errorf(codes.Internal, "Failed to find device path for volume %s. %v", volumeID, err) + } + + ll = ll.WithField("source", source) if req.GetVolumeCapability() != nil { switch req.GetVolumeCapability().GetAccessType().(type) { case *csi.VolumeCapability_Block: - log.Info("filesystem expansion is skipped for block volumes") + ll.Info("filesystem expansion is skipped for block volumes") return &csi.NodeExpandVolumeResponse{}, nil } } - mounted, err := d.mounter.IsMounted(volumePath) + mounted, err := d.mounter.IsMounted(volumePath, ll) if err != nil { return nil, status.Errorf(codes.Internal, "NodeExpandVolume failed to check if volume path %q is mounted: %s", volumePath, err) } @@ -529,10 +547,10 @@ func (d *Driver) NodeExpandVolume(ctx context.Context, req *csi.NodeExpandVolume return nil, status.Errorf(codes.Internal, "NodeExpandVolume unable to test if volume %q at %q is encrypted with luks: %v", volumePath, devicePath, err) } - log = log.WithFields(logrus.Fields{ + ll = ll.WithFields(logrus.Fields{ "device_path": devicePath, }) - hasRequiredSize, err := d.mounter.HasRequiredSize(log, source, req.CapacityRange.RequiredBytes) + hasRequiredSize, err := d.mounter.HasRequiredSize(ll, source, req.CapacityRange.RequiredBytes) if err != nil { return nil, status.Errorf(codes.Internal, "NodeExpandVolume unable to test if volume %q at %q has required size: %v", volumePath, source, err) } @@ -544,9 +562,7 @@ func (d *Driver) NodeExpandVolume(ctx context.Context, req *csi.NodeExpandVolume // the luks container must be resized if the volume was resized while the disk was mounted if isLuks { - log.WithFields(logrus.Fields{ - "device_path": devicePath, - }).Info("resizing luks container") + ll.Info("resizing luks container") err := luksResize(devicePath) if err != nil { return nil, status.Errorf(codes.Internal, "NodeExpandVolume unable resize luks container for volume %q at %q: %v", volumePath, devicePath, err) @@ -554,16 +570,16 @@ func (d *Driver) NodeExpandVolume(ctx context.Context, req *csi.NodeExpandVolume } r := mount.NewResizeFs(utilexec.New()) - log.Info("resizing volume") + ll.Info("resizing volume") if _, err := r.Resize(devicePath, volumePath); err != nil { return nil, status.Errorf(codes.Internal, "NodeExpandVolume could not resize volume %q (%q): %v", volumeID, req.GetVolumePath(), err) } - log.Info("volume was resized") + ll.Info("volume was resized") return &csi.NodeExpandVolumeResponse{}, nil } -func (d *Driver) nodePublishVolumeForFileSystem(req *csi.NodePublishVolumeRequest, luksContext LuksContext, mountOptions []string, log *logrus.Entry) error { +func (d *Driver) nodePublishVolumeForFileSystem(req *csi.NodePublishVolumeRequest, luksContext LuksContext, mountOptions []string, ll *logrus.Entry) error { source := req.StagingTargetPath target := req.TargetPath @@ -575,39 +591,39 @@ func (d *Driver) nodePublishVolumeForFileSystem(req *csi.NodePublishVolumeReques fsType = mnt.FsType } - log = log.WithFields(logrus.Fields{ + ll = ll.WithFields(logrus.Fields{ "source_path": source, "volume_mode": volumeModeFilesystem, "fs_type": fsType, "mount_options": mountOptions, }) - log.Info("mounting the volume") - if err := d.mounter.Mount(source, target, fsType, luksContext, mountOptions...); err != nil { + ll.Info("mounting the volume") + if err := d.mounter.Mount(source, target, fsType, luksContext, ll, mountOptions...); err != nil { return status.Error(codes.Internal, err.Error()) } return nil } -func (d *Driver) nodePublishVolumeForBlock(req *csi.NodePublishVolumeRequest, luksContext LuksContext, mountOptions []string, log *logrus.Entry) error { +func (d *Driver) nodePublishVolumeForBlock(req *csi.NodePublishVolumeRequest, luksContext LuksContext, mountOptions []string, ll *logrus.Entry) error { volumeId := req.VolumeId - source, err := d.mounter.FindAbsoluteDeviceByIDPath(volumeId) + source, err := d.mounter.FindAbsoluteDeviceByIDPath(volumeId, ll) if err != nil { return status.Errorf(codes.Internal, "Failed to find device path for volume %s. %v", volumeId, err) } target := req.TargetPath - log = log.WithFields(logrus.Fields{ + ll = ll.WithFields(logrus.Fields{ "source_path": source, "volume_mode": volumeModeBlock, "mount_options": mountOptions, }) - log.Info("mounting the volume") - if err := d.mounter.Mount(source, target, "", luksContext, mountOptions...); err != nil { + ll.Info("mounting the volume") + if err := d.mounter.Mount(source, target, "", luksContext, ll, mountOptions...); err != nil { return status.Error(codes.Internal, err.Error()) }