Merge pull request #15586 from Budibase/dd-automations

Improve APM traces around automations.

packages/backend-core/src/context/mainContext.ts

@@ -123,7 +123,7 @@ export async function doInAutomationContext<T>(params: {
   task: () => T
 }): Promise<T> {
   await ensureSnippetContext()
-  return newContext(
+  return await newContext(
     {
       tenantId: getTenantIDFromAppID(params.appId),
       appId: params.appId,

packages/server/src/automations/utils.ts

@@ -40,21 +40,17 @@ function loggingArgs(job: AutomationJob) {
 }
 
 export async function processEvent(job: AutomationJob) {
-  return tracer.trace(
+  return tracer.trace("processEvent", async span => {
-    "processEvent",
-    { resource: "automation" },
-    async span => {
     const appId = job.data.event.appId!
     const automationId = job.data.automation._id!
 
-      span?.addTags({
+    span.addTags({
       appId,
       automationId,
       job: {
         id: job.id,
         name: job.name,
         attemptsMade: job.attemptsMade,
-          opts: {
         attempts: job.opts.attempts,
         priority: job.opts.priority,
         delay: job.opts.delay,
@@ -68,11 +64,11 @@ export async function processEvent(job: AutomationJob) {
         stackTraceLimit: job.opts.stackTraceLimit,
         preventParsingData: job.opts.preventParsingData,
       },
-        },
     })
 
     const task = async () => {
       try {
+        return await tracer.trace("task", async () => {
           if (isCronTrigger(job.data.automation) && !job.data.event.timestamp) {
             // Requires the timestamp at run time
             job.data.event.timestamp = Date.now()
@@ -81,25 +77,19 @@ export async function processEvent(job: AutomationJob) {
           console.log("automation running", ...loggingArgs(job))
 
           const runFn = () => Runner.run(job)
-          const result = await quotas.addAutomation(runFn, {
+          const result = await quotas.addAutomation(runFn, { automationId })
-            automationId,
-          })
           console.log("automation completed", ...loggingArgs(job))
           return result
+        })
       } catch (err) {
-          span?.addTags({ error: true })
+        span.addTags({ error: true })
-          console.error(
+        console.error(`automation was unable to run`, err, ...loggingArgs(job))
-            `automation was unable to run`,
-            err,
-            ...loggingArgs(job)
-          )
         return { err }
       }
     }
 
     return await context.doInAutomationContext({ appId, automationId, task })
-    }
+  })
-  )
 }
 
 export async function updateTestHistory(

packages/server/src/threads/automation.ts

@@ -310,11 +310,8 @@ class Orchestrator {
   }
 
   async execute(): Promise<AutomationResults> {
-    return tracer.trace(
+    return await tracer.trace("execute", async span => {
-      "Orchestrator.execute",
+      span.addTags({ appId: this.appId, automationId: this.automation._id })
-      { resource: "automation" },
-      async span => {
-        span?.addTags({ appId: this.appId, automationId: this.automation._id })
 
       const job = cloneDeep(this.job)
       delete job.data.event.appId
@@ -382,15 +379,14 @@ class Orchestrator {
       }
 
       return result
-      }
+    })
-    )
   }
 
   private async executeSteps(
     ctx: AutomationContext,
     steps: AutomationStep[]
   ): Promise<AutomationStepResult[]> {
-    return tracer.trace("Orchestrator.executeSteps", async () => {
+    return await tracer.trace("executeSteps", async () => {
       let stepIndex = 0
       const results: AutomationStepResult[] = []
 
@@ -446,6 +442,7 @@ class Orchestrator {
     step: LoopStep,
     stepToLoop: AutomationStep
   ): Promise<AutomationStepResult> {
+    return await tracer.trace("executeLoopStep", async span => {
       await processObject(step.inputs, prepareContext(ctx))
 
       const maxIterations = getLoopMaxIterations(step)
@@ -455,6 +452,10 @@ class Orchestrator {
       try {
         iterable = getLoopIterable(step)
       } catch (err) {
+        span.addTags({
+          status: AutomationStepStatus.INCORRECT_TYPE,
+          iterations,
+        })
         return stepFailure(stepToLoop, {
           status: AutomationStepStatus.INCORRECT_TYPE,
         })
@@ -464,6 +465,10 @@ class Orchestrator {
         const currentItem = iterable[iterations]
 
         if (iterations === maxIterations) {
+          span.addTags({
+            status: AutomationStepStatus.MAX_ITERATIONS,
+            iterations,
+          })
           return stepFailure(stepToLoop, {
             status: AutomationStepStatus.MAX_ITERATIONS,
             iterations,
@@ -471,6 +476,10 @@ class Orchestrator {
         }
 
         if (matchesLoopFailureCondition(step, currentItem)) {
+          span.addTags({
+            status: AutomationStepStatus.FAILURE_CONDITION,
+            iterations,
+          })
           return stepFailure(stepToLoop, {
             status: AutomationStepStatus.FAILURE_CONDITION,
           })
@@ -485,16 +494,19 @@ class Orchestrator {
       const status =
         iterations === 0 ? AutomationStatus.NO_CONDITION_MET : undefined
       return stepSuccess(stepToLoop, { status, iterations, items })
+    })
   }
 
   private async executeBranchStep(
     ctx: AutomationContext,
     step: BranchStep
   ): Promise<AutomationStepResult[]> {
+    return await tracer.trace("executeBranchStep", async span => {
       const { branches, children } = step.inputs
 
       for (const branch of branches) {
         if (await branchMatches(ctx, branch)) {
+          span.addTags({ branchName: branch.name, branchId: branch.id })
           return [
             stepSuccess(step, {
               branchName: branch.name,
@@ -506,14 +518,16 @@ class Orchestrator {
         }
       }
 
+      span.addTags({ status: AutomationStatus.NO_CONDITION_MET })
       return [stepFailure(step, { status: AutomationStatus.NO_CONDITION_MET })]
+    })
   }
 
   private async executeStep(
     ctx: AutomationContext,
     step: Readonly<AutomationStep>
   ): Promise<AutomationStepResult> {
-    return tracer.trace("Orchestrator.executeStep", async span => {
+    return await tracer.trace(step.stepId, async span => {
       span.addTags({
         step: {
           stepId: step.stepId,
@@ -524,6 +538,7 @@ class Orchestrator {
           internal: step.internal,
           deprecated: step.deprecated,
         },
+        inputsKeys: Object.keys(step.inputs),
       })
 
       if (this.stopped) {
@@ -557,6 +572,7 @@ class Orchestrator {
         ;(outputs as any).status = AutomationStatus.STOPPED
       }
 
+      span.addTags({ outputsKeys: Object.keys(outputs) })
       return stepSuccess(step, outputs, inputs)
     })
   }