From 8da1cfbca02f69d87b12b38e7fe6115383a5ddfd Mon Sep 17 00:00:00 2001 From: fullsend-code <278716306+fullsend-ai-coder[bot]@users.noreply.github.com> Date: Mon, 20 Jul 2026 21:38:41 +0000 Subject: [PATCH] fix(#975): add diagnostic context to provisioning error logs Replace generic "failed to provision host" messages with errors that include instance IDs, instance tags, platform, addresses, and failed host lists. This enables Splunk queries to distinguish AWS capacity errors from SSH failures, network issues, and timeouts. Changes: - dynamic.go: Include failed hosts list and instance tag when all provisioning attempts are exhausted. Add instance ID and timeout duration to timeout errors. Add structured log fields (instanceId, instanceTag, address) to all error log calls. - hostpool.go: Add host name, address, and platform to the provisioning task launch failure log. Use %w instead of %v for proper error chain preservation. - dynamicpool.go: Add error log with instanceTag and platform when LaunchInstance fails (previously silent). Add structured fields to pool allocation failure log. - Tests: Add diagnostic context verification tests for dynamic, static, and dynamic pool provisioning to assert error messages contain instance IDs, host names, and descriptive context. Closes #975 --- pkg/reconciler/taskrun/dynamic.go | 33 +++++++++---- pkg/reconciler/taskrun/dynamicpool.go | 12 ++++- pkg/reconciler/taskrun/hostpool.go | 8 +++- .../taskrun/provision_dynamic_test.go | 40 ++++++++++++++++ .../taskrun/provision_dynamicpool_test.go | 14 ++++++ .../taskrun/provision_static_test.go | 47 +++++++++++++++++++ 6 files changed, 142 insertions(+), 12 deletions(-) diff --git a/pkg/reconciler/taskrun/dynamic.go b/pkg/reconciler/taskrun/dynamic.go index d9b58b323..5dbf36724 100644 --- a/pkg/reconciler/taskrun/dynamic.go +++ b/pkg/reconciler/taskrun/dynamic.go @@ -2,7 +2,6 @@ package taskrun import ( "context" - "errors" "fmt" "strconv" "time" @@ -48,7 +47,11 @@ func (r DynamicResolver) Deallocate(taskRun *ReconcileTaskRun, ctx context.Conte func (r DynamicResolver) Allocate(taskRun *ReconcileTaskRun, ctx context.Context, tr *v1.TaskRun, secretName string) (reconcile.Result, error) { log := logr.FromContextOrDiscard(ctx) if tr.Annotations[FailedHosts] != "" { - return reconcile.Result{}, errors.New("failed to provision host") + log.Error(nil, "all provisioning attempts exhausted", + "failedHosts", tr.Annotations[FailedHosts], + "instanceTag", r.instanceTag, + ) + return reconcile.Result{}, fmt.Errorf("failed to provision host, all attempts exhausted for instance tag %s (previously failed hosts: %s)", r.instanceTag, tr.Annotations[FailedHosts]) } if tr.Annotations == nil { @@ -59,8 +62,12 @@ func (r DynamicResolver) Allocate(taskRun *ReconcileTaskRun, ctx context.Context startTime, err := strconv.ParseInt(allocStart, 10, 64) if err == nil { if startTime+r.timeout < time.Now().Unix() { - err = errors.New("timed out waiting for instance address") - log.Error(err, "timed out waiting for instance address") + err = fmt.Errorf("timed out waiting for instance address (instance: %s, instanceTag: %s, timeout: %ds)", tr.Annotations[CloudInstanceId], r.instanceTag, r.timeout) + log.Error(err, "timed out waiting for instance address", + "instanceId", tr.Annotations[CloudInstanceId], + "instanceTag", r.instanceTag, + "timeoutSeconds", r.timeout, + ) //ugh, try and unassign terr := r.TerminateInstance(taskRun.client, ctx, cloud.InstanceIdentifier(tr.Annotations[CloudInstanceId])) if terr != nil { @@ -85,7 +92,10 @@ func (r DynamicResolver) Allocate(taskRun *ReconcileTaskRun, ctx context.Context //An instance already exists, so get its IP address address, err := r.GetInstanceAddress(taskRun.client, ctx, cloud.InstanceIdentifier(tr.Annotations[CloudInstanceId])) if err != nil { // A permanent error occurred when fetching the IP address for the VM - log.Error(err, "failed to get instance address for cloud host") + log.Error(err, "failed to get instance address for cloud host", + "instanceId", tr.Annotations[CloudInstanceId], + "instanceTag", r.instanceTag, + ) //Try to delete the instance and unassign it from the TaskRun terr := r.TerminateInstance(taskRun.client, ctx, cloud.InstanceIdentifier(tr.Annotations[CloudInstanceId])) if terr != nil { @@ -124,9 +134,13 @@ func (r DynamicResolver) Allocate(taskRun *ReconcileTaskRun, ctx context.Context if unassignErr != nil { log.Error(unassignErr, "failed to unassign instance from task after provisioning failure") } else { - log.Error(err, "failed to provision cloud host") + log.Error(err, "failed to provision cloud host", + "instanceId", tr.Annotations[CloudInstanceId], + "instanceTag", r.instanceTag, + "address", address, + ) } - return reconcile.Result{}, err + return reconcile.Result{}, fmt.Errorf("failed to provision cloud host (instance: %s, address: %s): %w", tr.Annotations[CloudInstanceId], address, err) } return reconcile.Result{}, nil } else { // A transient error (that wasn't returned) occurred when fetching the IP address for the VM @@ -194,7 +208,10 @@ func (r DynamicResolver) Allocate(taskRun *ReconcileTaskRun, ctx context.Context if err != nil { launchErr := err //launch failed - log.Error(err, "Failed to create cloud host") + log.Error(err, "Failed to create cloud host", + "instanceTag", r.instanceTag, + "platform", r.platform, + ) failureCount := 0 existingFailureString := tr.Annotations[CloudFailures] if existingFailureString != "" { diff --git a/pkg/reconciler/taskrun/dynamicpool.go b/pkg/reconciler/taskrun/dynamicpool.go index 4d5bcd66f..97b1f7303 100644 --- a/pkg/reconciler/taskrun/dynamicpool.go +++ b/pkg/reconciler/taskrun/dynamicpool.go @@ -109,7 +109,11 @@ func (a DynamicHostPool) Allocate(r *ReconcileTaskRun, ctx context.Context, tr * if len(hostPool.hosts) > 0 { _, allocationErr = hostPool.Allocate(r, ctx, tr, secretName) if allocationErr != nil && !errors.Is(allocationErr, ErrAllHostsFailed) { - log.Error(allocationErr, "could not allocate host from pool") + log.Error(allocationErr, "could not allocate host from pool", + "instanceTag", a.instanceTag, + "platform", a.platform, + "poolSize", len(hostPool.hosts), + ) return reconcile.Result{}, allocationErr } if allocationErr == nil && (tr.Labels == nil || tr.Labels[constant.WaitingForPlatformLabel] == "") { @@ -143,7 +147,11 @@ func (a DynamicHostPool) Allocate(r *ReconcileTaskRun, ctx context.Context, tr * taskRunID := fmt.Sprintf("%s:%s", tr.Namespace, tr.Name) inst, err := a.cloudProvider.LaunchInstance(r.client, ctx, taskRunID, a.instanceTag, a.additionalInstanceTags) if err != nil { - return reconcile.Result{}, err + log.Error(err, "failed to launch new instance for dynamic pool", + "instanceTag", a.instanceTag, + "platform", a.platform, + ) + return reconcile.Result{}, fmt.Errorf("failed to launch instance for dynamic pool (instanceTag: %s, platform: %s): %w", a.instanceTag, a.platform, err) } log.Info("allocated instance", "instance", inst) diff --git a/pkg/reconciler/taskrun/hostpool.go b/pkg/reconciler/taskrun/hostpool.go index 592f9ec04..141f388f6 100644 --- a/pkg/reconciler/taskrun/hostpool.go +++ b/pkg/reconciler/taskrun/hostpool.go @@ -135,7 +135,11 @@ func (hp HostPool) Allocate(r *ReconcileTaskRun, ctx context.Context, tr *v1.Tas if err != nil { //ugh, try and unassign - log.Error(err, "failed to launch provisioning task, unassigning host") + log.Error(err, "failed to launch provisioning task, unassigning host", + "host", selected.Name, + "address", selected.Address, + "platform", hp.targetPlatform, + ) delete(tr.Labels, constant.AssignedHost) controllerutil.RemoveFinalizer(tr, PipelineFinalizer) updateErr := UpdateTaskRunWithRetry(ctx, r.client, r.apiReader, tr) @@ -143,7 +147,7 @@ func (hp HostPool) Allocate(r *ReconcileTaskRun, ctx context.Context, tr *v1.Tas log.Error(updateErr, "Could not unassign task after provisioning failure") return reconcile.Result{}, err } - return reconcile.Result{}, fmt.Errorf("failed to provision host: %v", err) + return reconcile.Result{}, fmt.Errorf("failed to provision host %s (%s): %w", selected.Name, selected.Address, err) } return reconcile.Result{}, nil } diff --git a/pkg/reconciler/taskrun/provision_dynamic_test.go b/pkg/reconciler/taskrun/provision_dynamic_test.go index 54a8c0f45..85440d964 100644 --- a/pkg/reconciler/taskrun/provision_dynamic_test.go +++ b/pkg/reconciler/taskrun/provision_dynamic_test.go @@ -283,6 +283,46 @@ var _ = Describe("Test Dynamic Host Provisioning", func() { }) }) + When("error messages contain diagnostic context", func() { + + It("should include failed hosts and instance tag in error when all provisioning attempts are exhausted", func(ctx SpecContext) { + createUserTaskRun(ctx, client, "test-err-ctx", "linux/arm64") + tr := getUserTaskRun(ctx, client, "test-err-ctx") + // Simulate that a previous host already failed + tr.Annotations = map[string]string{FailedHosts: "host-abc"} + Expect(client.Update(ctx, tr)).ShouldNot(HaveOccurred()) + + _, err := reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: userNamespace, Name: "test-err-ctx"}}) + Expect(err).Should(HaveOccurred()) + Expect(err.Error()).Should(ContainSubstring("host-abc")) + Expect(err.Error()).Should(ContainSubstring("all attempts exhausted")) + }) + + It("should include instance ID and timeout in error when instance address times out", func(ctx SpecContext) { + cloudImpl.TimeoutGetAddress = true + defer func() { cloudImpl.TimeoutGetAddress = false }() + + createUserTaskRun(ctx, client, "test-timeout-ctx", "linux/arm64") + // 1st reconcile: launches instance + _, err := reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: userNamespace, Name: "test-timeout-ctx"}}) + Expect(err).ShouldNot(HaveOccurred()) + + // Verify instance was created and has an ID + tr := getUserTaskRun(ctx, client, "test-timeout-ctx") + Expect(tr.Annotations[CloudInstanceId]).ShouldNot(BeEmpty()) + instanceID := tr.Annotations[CloudInstanceId] + + // Wait for timeout (allocation-timeout is 2 seconds in test config) + time.Sleep(time.Second * 3) + + // Reconcile after timeout + _, err = reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: userNamespace, Name: "test-timeout-ctx"}}) + Expect(err).Should(HaveOccurred()) + Expect(err.Error()).Should(ContainSubstring("timed out")) + Expect(err.Error()).Should(ContainSubstring(instanceID)) + }) + }) + // Tests for buildDynamicResolver function - only the sad paths since happy paths are thoroughly tested elsewhere When("testing buildDynamicResolver error paths", func() { It("should use default instance tag when platform config doesn't specify one", func(ctx SpecContext) { diff --git a/pkg/reconciler/taskrun/provision_dynamicpool_test.go b/pkg/reconciler/taskrun/provision_dynamicpool_test.go index f67609aca..e538ea65f 100644 --- a/pkg/reconciler/taskrun/provision_dynamicpool_test.go +++ b/pkg/reconciler/taskrun/provision_dynamicpool_test.go @@ -165,6 +165,20 @@ var _ = Describe("Test Dynamic Pool Host Provisioning", func() { }) }) + When("error messages contain diagnostic context", func() { + + It("should include instance tag and platform in error when launch fails in dynamic pool", func(ctx SpecContext) { + cloudImpl.FailLaunch = true + defer func() { cloudImpl.FailLaunch = false }() + + createUserTaskRun(ctx, client, "test-pool-launch-err", "linux/arm64") + _, err := reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: userNamespace, Name: "test-pool-launch-err"}}) + Expect(err).Should(HaveOccurred()) + Expect(err.Error()).Should(ContainSubstring("dynamic pool")) + Expect(err.Error()).Should(ContainSubstring("launch failed")) + }) + }) + // Tests for buildDynamicHostPool function When("testing buildDynamicHostPool error paths", func() { It("should use default instance tag when platform config doesn't specify one", func(ctx SpecContext) { diff --git a/pkg/reconciler/taskrun/provision_static_test.go b/pkg/reconciler/taskrun/provision_static_test.go index 9c692d513..b205c5a0b 100644 --- a/pkg/reconciler/taskrun/provision_static_test.go +++ b/pkg/reconciler/taskrun/provision_static_test.go @@ -192,6 +192,53 @@ var _ = Describe("Test Static Host Provisioning", func() { }) }) + When("error messages contain diagnostic context", func() { + + It("should include host details in error when all hosts have been tried", func(ctx SpecContext) { + tr := runUserPipeline(ctx, client, reconciler, "test-err-hosts") + provision1 := getProvisionTaskRun(ctx, client, tr) + host1 := provision1.Labels[AssignedHost] + + // Fail the first host + provision1.Status.CompletionTime = &metav1.Time{Time: time.Now()} + provision1.Status.SetCondition(&apis.Condition{ + Type: apis.ConditionSucceeded, + Status: v1.ConditionFalse, + }) + Expect(client.Status().Update(ctx, provision1)).ShouldNot(HaveOccurred()) + _, err := reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: provision1.Namespace, Name: provision1.Name}}) + Expect(err).ShouldNot(HaveOccurred()) + Expect(client.Delete(ctx, provision1)).Should(Succeed()) + + // Reconcile the user task to try the next host + tr = getUserTaskRun(ctx, client, "test-err-hosts") + _, err = reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: tr.Namespace, Name: tr.Name}}) + Expect(err).ShouldNot(HaveOccurred()) + + // Fail the second host + provision2 := getProvisionTaskRun(ctx, client, tr) + provision2.Status.CompletionTime = &metav1.Time{Time: time.Now()} + provision2.Status.SetCondition(&apis.Condition{ + Type: apis.ConditionSucceeded, + Status: v1.ConditionFalse, + }) + Expect(client.Status().Update(ctx, provision2)).ShouldNot(HaveOccurred()) + _, err = reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: provision2.Namespace, Name: provision2.Name}}) + Expect(err).ShouldNot(HaveOccurred()) + + // Final reconcile should fail and include failed host names + tr = getUserTaskRun(ctx, client, "test-err-hosts") + _, err = reconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Namespace: tr.Namespace, Name: tr.Name}}) + Expect(err).Should(HaveOccurred()) + Expect(err.Error()).Should(ContainSubstring(host1)) + Expect(err.Error()).Should(ContainSubstring("all available hosts")) + + secret := getSecret(ctx, client, tr) + Expect(secret.Data["error"]).ShouldNot(BeEmpty()) + Expect(string(secret.Data["error"])).Should(ContainSubstring(host1)) + }) + }) + When("when provisioning succeeds", func() { // It tests a specific failure case where the provisioner TaskRun reports