From ddac66d76bc8e9609d11878d7acd384d239d09d6 Mon Sep 17 00:00:00 2001 From: Niels de Vos Date: Wed, 22 Jul 2020 14:11:41 +0200 Subject: [PATCH] util: use context.Context for logging in ExecCommand All calls to util.ExecCommand() now pass the context.Context. In some cases this is not possible or needed, and util.ExecCommand() will not log the command. This should make debugging easier when command executions fail. Signed-off-by: Niels de Vos --- internal/cephfs/util.go | 4 ++-- internal/cephfs/volume.go | 1 + internal/cephfs/volumemounter.go | 2 +- internal/rbd/rbd_attach.go | 14 +++++++------- internal/rbd/rbd_util.go | 12 ++++++++---- internal/util/cephcmds.go | 17 +++++++++++++---- 6 files changed, 32 insertions(+), 18 deletions(-) diff --git a/internal/cephfs/util.go b/internal/cephfs/util.go index 895fab15d..9142423fa 100644 --- a/internal/cephfs/util.go +++ b/internal/cephfs/util.go @@ -31,12 +31,12 @@ import ( type volumeID string func execCommandErr(ctx context.Context, program string, args ...string) error { - _, _, err := util.ExecCommand(program, args...) + _, _, err := util.ExecCommand(ctx, program, args...) return err } func execCommandJSON(ctx context.Context, v interface{}, program string, args ...string) error { - stdout, _, err := util.ExecCommand(program, args...) + stdout, _, err := util.ExecCommand(ctx, program, args...) if err != nil { return err } diff --git a/internal/cephfs/volume.go b/internal/cephfs/volume.go index d2db16786..ddfa13042 100644 --- a/internal/cephfs/volume.go +++ b/internal/cephfs/volume.go @@ -52,6 +52,7 @@ func getVolumeRootPathCephDeprecated(volID volumeID) string { func getVolumeRootPathCeph(ctx context.Context, volOptions *volumeOptions, cr *util.Credentials, volID volumeID) (string, error) { stdout, stderr, err := util.ExecCommand( + ctx, "ceph", "fs", "subvolume", diff --git a/internal/cephfs/volumemounter.go b/internal/cephfs/volumemounter.go index 39adeee1a..5bc8a61c0 100644 --- a/internal/cephfs/volumemounter.go +++ b/internal/cephfs/volumemounter.go @@ -167,7 +167,7 @@ func mountFuse(ctx context.Context, mountPoint string, cr *util.Credentials, vol args = append(args, "--client_mds_namespace="+volOptions.FsName) } - _, stderr, err := util.ExecCommand("ceph-fuse", args[:]...) + _, stderr, err := util.ExecCommand(ctx, "ceph-fuse", args[:]...) if err != nil { return err } diff --git a/internal/rbd/rbd_attach.go b/internal/rbd/rbd_attach.go index 16b7c256b..d05621b1b 100644 --- a/internal/rbd/rbd_attach.go +++ b/internal/rbd/rbd_attach.go @@ -77,14 +77,14 @@ type nbdDeviceInfo struct { // rbdGetDeviceList queries rbd about mapped devices and returns a list of rbdDeviceInfo // It will selectively list devices mapped using krbd or nbd as specified by accessType. -func rbdGetDeviceList(accessType string) ([]rbdDeviceInfo, error) { +func rbdGetDeviceList(ctx context.Context, accessType string) ([]rbdDeviceInfo, error) { // rbd device list --format json --device-type [krbd|nbd] var ( rbdDeviceList []rbdDeviceInfo nbdDeviceList []nbdDeviceInfo ) - stdout, _, err := util.ExecCommand(rbd, "device", "list", "--format="+"json", "--device-type", accessType) + stdout, _, err := util.ExecCommand(ctx, rbd, "device", "list", "--format="+"json", "--device-type", accessType) if err != nil { return nil, fmt.Errorf("error getting device list from rbd for devices of type (%s): (%v)", accessType, err) } @@ -122,7 +122,7 @@ func findDeviceMappingImage(ctx context.Context, pool, image string, useNbdDrive accessType = accessTypeNbd } - rbdDeviceList, err := rbdGetDeviceList(accessType) + rbdDeviceList, err := rbdGetDeviceList(ctx, accessType) if err != nil { klog.Warningf(util.Log(ctx, "failed to determine if image (%s/%s) is mapped to a device (%v)"), pool, image, err) return "", false @@ -159,13 +159,13 @@ func checkRbdNbdTools() bool { _, err := os.Stat(fmt.Sprintf("/sys/module/%s", moduleNbd)) if os.IsNotExist(err) { // try to load the module - _, _, err = util.ExecCommand("modprobe", moduleNbd) + _, _, err = util.ExecCommand(context.TODO(), "modprobe", moduleNbd) if err != nil { util.ExtendedLogMsg("rbd-nbd: nbd modprobe failed with error %v", err) return false } } - if _, _, err := util.ExecCommand(rbdTonbd, "--version"); err != nil { + if _, _, err := util.ExecCommand(context.TODO(), rbdTonbd, "--version"); err != nil { util.ExtendedLogMsg("rbd-nbd: running rbd-nbd --version failed with error %v", err) return false } @@ -229,7 +229,7 @@ func createPath(ctx context.Context, volOpt *rbdVolume, cr *util.Credentials) (s mapOptions = append(mapOptions, "--read-only") } // Execute map - stdout, stderr, err := util.ExecCommand(rbd, mapOptions...) + stdout, stderr, err := util.ExecCommand(ctx, rbd, mapOptions...) if err != nil { klog.Warningf(util.Log(ctx, "rbd: map error %v, rbd output: %s"), err, string(stderr)) // unmap rbd image if connection timeout @@ -306,7 +306,7 @@ func detachRBDImageOrDeviceSpec(ctx context.Context, imageOrDeviceSpec string, i } options := []string{"unmap", "--device-type", accessType, imageOrDeviceSpec} - _, stderr, err := util.ExecCommand(rbd, options...) + _, stderr, err := util.ExecCommand(ctx, rbd, options...) if err != nil { // Messages for krbd and nbd differ, hence checking either of them for missing mapping // This is not applicable when a device path is passed in diff --git a/internal/rbd/rbd_util.go b/internal/rbd/rbd_util.go index 363c6325b..3a90a8d80 100644 --- a/internal/rbd/rbd_util.go +++ b/internal/rbd/rbd_util.go @@ -303,7 +303,7 @@ func addRbdManagerTask(ctx context.Context, pOpts *rbdVolume, arg []string) (boo args = append(args, arg...) util.DebugLog(ctx, "executing %v for image (%s) using mon %s, pool %s", args, pOpts.RbdImageName, pOpts.Monitors, pOpts.Pool) supported := true - _, stderr, err := util.ExecCommand("ceph", args...) + _, stderr, err := util.ExecCommand(ctx, "ceph", args...) if err != nil { switch { @@ -872,7 +872,9 @@ func (rv *rbdVolume) updateVolWithImageInfo(cr *util.Credentials) error { // rbd --format=json info [image-spec | snap-spec] var imgInfo imageInfo - stdout, stderr, err := util.ExecCommand("rbd", + stdout, stderr, err := util.ExecCommand( + context.TODO(), + "rbd", "-m", rv.Monitors, "--id", cr.ID, "--keyfile="+cr.KeyFile, @@ -1046,7 +1048,7 @@ func resizeRBDImage(rbdVol *rbdVolume, cr *util.Credentials) error { volSzMiB := fmt.Sprintf("%dM", util.RoundOffVolSize(rbdVol.VolSize)) args := []string{"resize", rbdVol.String(), "--size", volSzMiB, "--id", cr.ID, "-m", mon, "--keyfile=" + cr.KeyFile} - _, stderr, err := util.ExecCommand("rbd", args...) + _, stderr, err := util.ExecCommand(context.TODO(), "rbd", args...) if err != nil { return fmt.Errorf("failed to resize rbd image (%w), command output: %s", err, string(stderr)) @@ -1114,7 +1116,9 @@ type snapshotInfo struct { func (rv *rbdVolume) listSnapshots(ctx context.Context, cr *util.Credentials) ([]snapshotInfo, error) { // rbd snap ls --pool= --all --format=json var snapInfo []snapshotInfo - stdout, stderr, err := util.ExecCommand("rbd", + stdout, stderr, err := util.ExecCommand( + ctx, + "rbd", "-m", rv.Monitors, "--id", cr.ID, "--keyfile="+cr.KeyFile, diff --git a/internal/util/cephcmds.go b/internal/util/cephcmds.go index 62b465e93..17453be41 100644 --- a/internal/util/cephcmds.go +++ b/internal/util/cephcmds.go @@ -30,8 +30,10 @@ import ( // InvalidPoolID used to denote an invalid pool. const InvalidPoolID int64 = -1 -// ExecCommand executes passed in program with args and returns separate stdout and stderr streams. -func ExecCommand(program string, args ...string) (stdout, stderr []byte, err error) { +// ExecCommand executes passed in program with args and returns separate stdout +// and stderr streams. In case ctx is not set to context.TODO(), the command +// will be logged after it was executed. +func ExecCommand(ctx context.Context, program string, args ...string) (stdout, stderr []byte, err error) { var ( cmd = exec.Command(program, args...) // #nosec:G204, commands executing not vulnerable. sanitizedArgs = StripSecretInArgs(args) @@ -43,8 +45,15 @@ func ExecCommand(program string, args ...string) (stdout, stderr []byte, err err cmd.Stderr = &stderrBuf if err := cmd.Run(); err != nil { - return stdoutBuf.Bytes(), stderrBuf.Bytes(), fmt.Errorf("an error (%v)"+ - " occurred while running %s args: %v", err, program, sanitizedArgs) + err = fmt.Errorf("an error (%w) occurred while running %s args: %v", err, program, sanitizedArgs) + if ctx != context.TODO() { + UsefulLog(ctx, "%s", err) + } + return stdoutBuf.Bytes(), stderrBuf.Bytes(), err + } + + if ctx != context.TODO() { + UsefulLog(ctx, "command succeeded: %s %v", program, sanitizedArgs) } return stdoutBuf.Bytes(), nil, nil