Log when a hook timeout duration can't be parsed (#2610)

Signed-off-by: Nolan Brubaker <brubakern@vmware.com>

changelogs/unreleased/2610-nrb

@@ -0,0 +1 @@
+When a timeout string can't be parsed, log the error as a warning instead of silently consuming the error.

pkg/backup/item_hook_handler.go

@@ -83,10 +83,10 @@ func (h *defaultItemHookHandler) handleHooks(
 	name := metadata.GetName()
 
 	// If the pod has the hook specified via annotations, that takes priority.
-	hookFromAnnotations := getPodExecHookFromAnnotations(metadata.GetAnnotations(), phase)
+	hookFromAnnotations := getPodExecHookFromAnnotations(metadata.GetAnnotations(), phase, log)
 	if phase == hookPhasePre && hookFromAnnotations == nil {
 		// See if the pod has the legacy hook annotation keys (i.e. without a phase specified)
-		hookFromAnnotations = getPodExecHookFromAnnotations(metadata.GetAnnotations(), "")
+		hookFromAnnotations = getPodExecHookFromAnnotations(metadata.GetAnnotations(), "", log)
 	}
 	if hookFromAnnotations != nil {
 		hookLog := log.WithFields(
@@ -164,7 +164,8 @@ func getHookAnnotation(annotations map[string]string, key string, phase hookPhas
 
 // getPodExecHookFromAnnotations returns an ExecHook based on the annotations, as long as the
 // 'command' annotation is present. If it is absent, this returns nil.
-func getPodExecHookFromAnnotations(annotations map[string]string, phase hookPhase) *api.ExecHook {
+// If there is an error in parsing a supplied timeout, it is logged.
+func getPodExecHookFromAnnotations(annotations map[string]string, phase hookPhase, log logrus.FieldLogger) *api.ExecHook {
 	commandValue := getHookAnnotation(annotations, podBackupHookCommandAnnotationKey, phase)
 	if commandValue == "" {
 		return nil
@@ -192,7 +193,7 @@ func getPodExecHookFromAnnotations(annotations map[string]string, phase hookPhas
 		if temp, err := time.ParseDuration(timeoutString); err == nil {
 			timeout = temp
 		} else {
-			// TODO: log error that we couldn't parse duration
+			log.Warn(errors.Wrapf(err, "Unable to parse provided timeout %s, using default", timeoutString))
 		}
 	}
 

pkg/backup/item_hook_handler_test.go

@@ -575,7 +575,7 @@ func TestGetPodExecHookFromAnnotations(t *testing.T) {
 				},
 			},
 			{
-				name: "invalid timeout is ignored",
+				name: "invalid timeout is logged",
 				annotations: map[string]string{
 					phasedKey(phase, podBackupHookCommandAnnotationKey): "/usr/bin/foo",
 					phasedKey(phase, podBackupHookTimeoutAnnotationKey): "invalid",
@@ -599,7 +599,8 @@ func TestGetPodExecHookFromAnnotations(t *testing.T) {
 
 		for _, test := range tests {
 			t.Run(fmt.Sprintf("%s (phase=%q)", test.name, phase), func(t *testing.T) {
-				hook := getPodExecHookFromAnnotations(test.annotations, phase)
+				l := velerotest.NewLogger()
+				hook := getPodExecHookFromAnnotations(test.annotations, phase, l)
 				assert.Equal(t, test.expectedHook, hook)
 			})
 		}