From 11d1289afa27d18941bf2fa1a305116a38cdf396 Mon Sep 17 00:00:00 2001 From: Scott Creeley Date: Fri, 22 Apr 2016 11:59:36 -0400 Subject: [PATCH] Add volume and mount logging --- pkg/util/mount/mount_linux.go | 10 +++++++++- pkg/volume/aws_ebs/aws_ebs.go | 15 +++++++++++---- pkg/volume/cinder/cinder.go | 4 +++- pkg/volume/flexvolume/flexvolume.go | 16 ++++++++++------ pkg/volume/gce_pd/gce_pd.go | 6 ++++++ pkg/volume/rbd/rbd.go | 3 ++- 6 files changed, 41 insertions(+), 13 deletions(-) diff --git a/pkg/util/mount/mount_linux.go b/pkg/util/mount/mount_linux.go index 8ded32bd3e3..03a5ccae755 100644 --- a/pkg/util/mount/mount_linux.go +++ b/pkg/util/mount/mount_linux.go @@ -107,7 +107,8 @@ func doMount(source string, target string, fstype string, options []string) erro command := exec.Command("mount", mountArgs...) output, err := command.CombinedOutput() if err != nil { - return fmt.Errorf("Mount failed: %v\nMounting arguments: %s %s %s %v\nOutput: %s\n", + glog.Errorf("Mount failed: %v\nMounting arguments: %s %s %s %v\nOutput: %s\n", err, source, target, fstype, options, string(output)) + return fmt.Errorf("mount failed: %v\nMounting arguments: %s %s %s %v\nOutput: %s\n", err, source, target, fstype, options, string(output)) } return err @@ -299,6 +300,7 @@ func (mounter *SafeFormatAndMount) formatAndMount(source string, target string, options = append(options, "defaults") // Run fsck on the disk to fix repairable issues + glog.V(4).Infof("Checking for issues with fsck on disk: %s", source) args := []string{"-a", source} cmd := mounter.Runner.Command("fsck", args...) out, err := cmd.CombinedOutput() @@ -317,6 +319,7 @@ func (mounter *SafeFormatAndMount) formatAndMount(source string, target string, } // Try to mount the disk + glog.V(4).Infof("Attempting to mount disk: %s %s %s", fstype, source, target) err = mounter.Interface.Mount(source, target, fstype, options) if err != nil { // It is possible that this disk is not formatted. Double check using diskLooksUnformatted @@ -331,12 +334,15 @@ func (mounter *SafeFormatAndMount) formatAndMount(source string, target string, if fstype == "ext4" || fstype == "ext3" { args = []string{"-E", "lazy_itable_init=0,lazy_journal_init=0", "-F", source} } + glog.Infof("Disk %q appears to be unformatted, attempting to format as type: %q with options: %v", source, fstype, args) cmd := mounter.Runner.Command("mkfs."+fstype, args...) _, err := cmd.CombinedOutput() if err == nil { // the disk has been formatted successfully try to mount it again. + glog.Infof("Disk successfully formatted (mkfs): %s - %s %s", fstype, source, target) return mounter.Interface.Mount(source, target, fstype, options) } + glog.Errorf("format of disk %q failed: type:(%q) target:(%q) options:(%q)error:(%v)", source, fstype, target, options, err) return err } } @@ -347,6 +353,7 @@ func (mounter *SafeFormatAndMount) formatAndMount(source string, target string, func (mounter *SafeFormatAndMount) diskLooksUnformatted(disk string) (bool, error) { args := []string{"-nd", "-o", "FSTYPE", disk} cmd := mounter.Runner.Command("lsblk", args...) + glog.V(4).Infof("Attempting to determine if disk %q is formatted using lsblk with args: (%v)", disk, args) dataOut, err := cmd.CombinedOutput() output := strings.TrimSpace(string(dataOut)) @@ -354,6 +361,7 @@ func (mounter *SafeFormatAndMount) diskLooksUnformatted(disk string) (bool, erro // an error if so. if err != nil { + glog.Errorf("Could not determine if disk %q is formatted (%v)", disk, err) return false, err } diff --git a/pkg/volume/aws_ebs/aws_ebs.go b/pkg/volume/aws_ebs/aws_ebs.go index 01c54dca55a..b2831da3a57 100644 --- a/pkg/volume/aws_ebs/aws_ebs.go +++ b/pkg/volume/aws_ebs/aws_ebs.go @@ -147,6 +147,7 @@ func (plugin *awsElasticBlockStorePlugin) NewDeleter(spec *volume.Spec) (volume. func (plugin *awsElasticBlockStorePlugin) newDeleterInternal(spec *volume.Spec, manager ebsManager) (volume.Deleter, error) { if spec.PersistentVolume != nil && spec.PersistentVolume.Spec.AWSElasticBlockStore == nil { + glog.Errorf("spec.PersistentVolumeSource.AWSElasticBlockStore is nil") return nil, fmt.Errorf("spec.PersistentVolumeSource.AWSElasticBlockStore is nil") } return &awsElasticBlockStoreDeleter{ @@ -242,6 +243,7 @@ func (b *awsElasticBlockStoreMounter) SetUpAt(dir string, fsGroup *int64) error notMnt, err := b.mounter.IsLikelyNotMountPoint(dir) glog.V(4).Infof("PersistentDisk set up: %s %v %v", dir, !notMnt, err) if err != nil && !os.IsNotExist(err) { + glog.Errorf("cannot validate mount point: %s %v", dir, err) return err } if !notMnt { @@ -263,17 +265,17 @@ func (b *awsElasticBlockStoreMounter) SetUpAt(dir string, fsGroup *int64) error if err != nil { notMnt, mntErr := b.mounter.IsLikelyNotMountPoint(dir) if mntErr != nil { - glog.Errorf("IsLikelyNotMountPoint check failed: %v", mntErr) + glog.Errorf("IsLikelyNotMountPoint check failed for %s: %v", dir, mntErr) return err } if !notMnt { if mntErr = b.mounter.Unmount(dir); mntErr != nil { - glog.Errorf("Failed to unmount: %v", mntErr) + glog.Errorf("failed to unmount %s: %v", dir, mntErr) return err } notMnt, mntErr := b.mounter.IsLikelyNotMountPoint(dir) if mntErr != nil { - glog.Errorf("IsLikelyNotMountPoint check failed: %v", mntErr) + glog.Errorf("IsLikelyNotMountPoint check failed for %s: %v", dir, mntErr) return err } if !notMnt { @@ -283,6 +285,7 @@ func (b *awsElasticBlockStoreMounter) SetUpAt(dir string, fsGroup *int64) error } } os.Remove(dir) + glog.Errorf("Mount of disk %s failed: %v", dir, err) return err } @@ -290,6 +293,7 @@ func (b *awsElasticBlockStoreMounter) SetUpAt(dir string, fsGroup *int64) error volume.SetVolumeOwnership(b, fsGroup) } + glog.V(4).Infof("Successfully mounted %s", dir) return nil } @@ -305,10 +309,12 @@ func getVolumeIDFromGlobalMount(host volume.VolumeHost, globalPath string) (stri basePath := path.Join(host.GetPluginDir(awsElasticBlockStorePluginName), "mounts") rel, err := filepath.Rel(basePath, globalPath) if err != nil { + glog.Errorf("Failed to get volume id from global mount %s - %v", globalPath, err) return "", err } if strings.Contains(rel, "../") { - return "", fmt.Errorf("Unexpected mount path: " + globalPath) + glog.Errorf("Unexpected mount path: %s", globalPath) + return "", fmt.Errorf("unexpected mount path: " + globalPath) } // Reverse the :// replacement done in makeGlobalPDPath volumeID := rel @@ -391,6 +397,7 @@ var _ volume.Provisioner = &awsElasticBlockStoreProvisioner{} func (c *awsElasticBlockStoreProvisioner) Provision() (*api.PersistentVolume, error) { volumeID, sizeGB, labels, err := c.manager.CreateVolume(c) if err != nil { + glog.Errorf("Provision failed: %v", err) return nil, err } diff --git a/pkg/volume/cinder/cinder.go b/pkg/volume/cinder/cinder.go index 9d314bc13e6..75e8a6d7352 100644 --- a/pkg/volume/cinder/cinder.go +++ b/pkg/volume/cinder/cinder.go @@ -277,7 +277,7 @@ func (b *cinderVolumeMounter) SetUpAt(dir string, fsGroup *int64) error { // TODO: handle failed mounts here. notmnt, err := b.mounter.IsLikelyNotMountPoint(dir) if err != nil && !os.IsNotExist(err) { - glog.V(4).Infof("IsLikelyNotMountPoint failed: %v", err) + glog.Errorf("Cannot validate mount point: %s %v", dir, err) return err } if !notmnt { @@ -299,6 +299,7 @@ func (b *cinderVolumeMounter) SetUpAt(dir string, fsGroup *int64) error { } // Perform a bind mount to the full path to allow duplicate mounts of the same PD. + glog.V(4).Infof("Attempting to mount cinder volume %s to %s with options %v", b.pdName, dir, options) err = b.mounter.Mount(globalPDPath, dir, "", options) if err != nil { glog.V(4).Infof("Mount failed: %v", err) @@ -326,6 +327,7 @@ func (b *cinderVolumeMounter) SetUpAt(dir string, fsGroup *int64) error { os.Remove(dir) // TODO: we should really eject the attach/detach out into its own control loop. detachDiskLogError(b.cinderVolume) + glog.Errorf("Failed to mount %s: %v", dir, err) return err } diff --git a/pkg/volume/flexvolume/flexvolume.go b/pkg/volume/flexvolume/flexvolume.go index 8c4d13ab9ca..eb4642ca7c0 100644 --- a/pkg/volume/flexvolume/flexvolume.go +++ b/pkg/volume/flexvolume/flexvolume.go @@ -265,7 +265,7 @@ func (f *flexVolumeMounter) SetUpAt(dir string, fsGroup *int64) error { notmnt, err := f.blockDeviceMounter.IsLikelyNotMountPoint(dir) if err != nil && !os.IsNotExist(err) { - glog.Errorf("Cannot validate mountpoint: %s", dir) + glog.Errorf("Cannot validate mount point: %s %v", dir, err) return err } if !notmnt { @@ -290,18 +290,20 @@ func (f *flexVolumeMounter) SetUpAt(dir string, fsGroup *int64) error { f.options[optionKeySecret+"/"+name] = secret } + glog.V(4).Infof("attempting to attach volume: %s with options %v", f.volName, f.options) device, err := f.manager.attach(f) if err != nil { if !isCmdNotSupportedErr(err) { - glog.Errorf("Failed to attach volume: %s", f.volName) + glog.Errorf("failed to attach volume: %s", f.volName) return err } // Attach not supported or required. Continue to mount. } + glog.V(4).Infof("attempting to mount volume: %s", f.volName) if err := f.manager.mount(f, device, dir); err != nil { if !isCmdNotSupportedErr(err) { - glog.Errorf("Failed to mount volume: %s", f.volName) + glog.Errorf("failed to mount volume: %s", f.volName) return err } options := make([]string, 0) @@ -318,13 +320,15 @@ func (f *flexVolumeMounter) SetUpAt(dir string, fsGroup *int64) error { os.MkdirAll(dir, 0750) // Mount not supported by driver. Use core mounting logic. + glog.V(4).Infof("attempting to mount the volume: %s to device: %s", f.volName, device) err = f.blockDeviceMounter.Mount(string(device), dir, f.fsType, options) if err != nil { - glog.Errorf("Failed to mount the volume: %s, device: %s, error: %s", f.volName, device, err.Error()) + glog.Errorf("failed to mount the volume: %s to device: %s, error: %v", f.volName, device, err) return err } } + glog.V(4).Infof("Successfully mounted volume: %s on device: %s", f.volName, device) return nil } @@ -370,7 +374,7 @@ func (f *flexVolumeUnmounter) TearDownAt(dir string) error { } // Unmount not supported by the driver. Use core unmount logic. if err := f.mounter.Unmount(dir); err != nil { - glog.Errorf("Failed to unmount volume: %s, error: %s", dir, err.Error()) + glog.Errorf("Failed to unmount volume: %s, error: %v", dir, err) return err } } @@ -378,7 +382,7 @@ func (f *flexVolumeUnmounter) TearDownAt(dir string) error { if refCount == 1 { if err := f.manager.detach(f, device); err != nil { if !isCmdNotSupportedErr(err) { - glog.Errorf("Failed to teardown volume: %s, error: %s", dir, err.Error()) + glog.Errorf("Failed to teardown volume: %s, error: %v", dir, err) return err } // Teardown not supported by driver. Unmount is good enough. diff --git a/pkg/volume/gce_pd/gce_pd.go b/pkg/volume/gce_pd/gce_pd.go index aba50f2a4e7..a3d57bd0e0c 100644 --- a/pkg/volume/gce_pd/gce_pd.go +++ b/pkg/volume/gce_pd/gce_pd.go @@ -234,6 +234,7 @@ func (b *gcePersistentDiskMounter) SetUpAt(dir string, fsGroup *int64) error { notMnt, err := b.mounter.IsLikelyNotMountPoint(dir) glog.V(4).Infof("PersistentDisk set up: %s %v %v, pd name %v readOnly %v", dir, !notMnt, err, b.pdName, b.readOnly) if err != nil && !os.IsNotExist(err) { + glog.Errorf("cannot validate mount point: %s %v", dir, err) return err } if !notMnt { @@ -241,6 +242,7 @@ func (b *gcePersistentDiskMounter) SetUpAt(dir string, fsGroup *int64) error { } if err := os.MkdirAll(dir, 0750); err != nil { + glog.Errorf("mkdir failed on disk %s (%v)", dir, err) return err } @@ -251,6 +253,8 @@ func (b *gcePersistentDiskMounter) SetUpAt(dir string, fsGroup *int64) error { } globalPDPath := makeGlobalPDName(b.plugin.host, b.pdName) + glog.V(4).Infof("attempting to mount %s", dir) + err = b.mounter.Mount(globalPDPath, dir, "", options) if err != nil { notMnt, mntErr := b.mounter.IsLikelyNotMountPoint(dir) @@ -275,6 +279,7 @@ func (b *gcePersistentDiskMounter) SetUpAt(dir string, fsGroup *int64) error { } } os.Remove(dir) + glog.Errorf("Mount of disk %s failed: %v", dir, err) return err } @@ -282,6 +287,7 @@ func (b *gcePersistentDiskMounter) SetUpAt(dir string, fsGroup *int64) error { volume.SetVolumeOwnership(b, fsGroup) } + glog.V(4).Infof("Successfully mounted %s", dir) return nil } diff --git a/pkg/volume/rbd/rbd.go b/pkg/volume/rbd/rbd.go index 239c981b897..94893cd7802 100644 --- a/pkg/volume/rbd/rbd.go +++ b/pkg/volume/rbd/rbd.go @@ -210,9 +210,10 @@ func (b *rbdMounter) SetUp(fsGroup *int64) error { func (b *rbdMounter) SetUpAt(dir string, fsGroup *int64) error { // diskSetUp checks mountpoints and prevent repeated calls + glog.V(4).Infof("rbd: attempting to SetUp and mount %s", dir) err := diskSetUp(b.manager, *b, dir, b.mounter, fsGroup) if err != nil { - glog.Errorf("rbd: failed to setup") + glog.Errorf("rbd: failed to setup mount %s %v", dir, err) } return err }