pulumi: up command of nodejs Automation API fails with SyntaxError after provisioning everything correctly

I’m using the Automation API to run tests (with jest) for my Pulumi infrastructure code. Approximately every sixth build fails because of an SyntaxError thrown by the pulumi up execution. The error happens after everything is provisioned. Everything works fine except that this error gets thrown. Here is a stack trace:

...
Resources:
    + 50 created

Duration: 16m53s

  console.error
    Unhandled error

      at process.uncaught (node_modules/jest-jasmine2/build/jasmine/Env.js:248:21)

  console.error
    Error [ERR_UNHANDLED_ERROR]: Unhandled error. (Error: An error was encountered while tailing the file
        at TailFile._streamFileChanges (/home/vsts/work/1/s/node_modules/@logdna/tail-file/lib/tail-file.js:252:21)
        at processTicksAndRejections (internal/process/task_queues.js:93:5)
        at TailFile._pollFileForChanges (/home/vsts/work/1/s/node_modules/@logdna/tail-file/lib/tail-file.js:196:9) {
      code: 'ETAIL',
      meta: {
        actual: Error [ERR_UNHANDLED_ERROR]: Unhandled error. (SyntaxError: Unexpected token a in JSON at position 0
            at JSON.parse (<anonymous>)
            at Transform.<anonymous> (/home/vsts/work/1/s/node_modules/@pulumi/pulumi/x/automation/stack.js:127:44)
            at Transform.emit (events.js:315:20)
            at addChunk (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_readable.js:298:12)
            at readableAddChunk (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_readable.js:280:11)
            at Transform.Readable.push (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_readable.js:241:10)
            at Transform.push (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_transform.js:139:32)
            at push (/home/vsts/work/1/s/node_modules/split2/index.js:73:10)
            at Transform.transform [as _transform] (/home/vsts/work/1/s/node_modules/split2/index.js:44:7)
            at Transform._read (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_transform.js:177:10))
            at Transform.emit (events.js:304:17)
            at Transform.onerror (internal/streams/readable.js:760:14)
            at Transform.emit (events.js:315:20)
            at errorOrDestroy (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/internal/streams/destroy.js:98:101)
            at onwriteError (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_writable.js:424:5)
            at onwrite (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_writable.js:450:11)
            at WritableState.onwrite (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_writable.js:160:5)
            at Transform.afterTransform (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_transform.js:89:3)
            at Transform.transform [as _transform] (/home/vsts/work/1/s/node_modules/split2/index.js:46:14)
            at Transform._read (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_transform.js:177:10) {
          code: 'ERR_UNHANDLED_ERROR',
          context: SyntaxError: Unexpected token a in JSON at position 0
              at JSON.parse (<anonymous>)
              at Transform.<anonymous> (/home/vsts/work/1/s/node_modules/@pulumi/pulumi/x/automation/stack.js:127:44)
              at Transform.emit (events.js:315:20)
              at addChunk (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_readable.js:298:12)
              at readableAddChunk (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_readable.js:280:11)
              at Transform.Readable.push (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_readable.js:241:10)
              at Transform.push (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_transform.js:139:32)
              at push (/home/vsts/work/1/s/node_modules/split2/index.js:73:10)
              at Transform.transform [as _transform] (/home/vsts/work/1/s/node_modules/split2/index.js:44:7)
              at Transform._read (/home/vsts/work/1/s/node_modules/split2/node_modules/readable-stream/lib/_stream_transform.js:177:10)
        }
      }
    })
        at TailFile.emit (events.js:304:17)
        at TailFile.quit (/home/vsts/work/1/s/node_modules/@logdna/tail-file/lib/tail-file.js:273:12)
        at TailFile._pollFileForChanges (/home/vsts/work/1/s/node_modules/@logdna/tail-file/lib/tail-file.js:230:19)
        at processTicksAndRejections (internal/process/task_queues.js:93:5)

      at process.uncaught (node_modules/jest-jasmine2/build/jasmine/Env.js:249:21)

If I understand the stack trace correctly, the error should be thrown here, which is inside a method called readLines. The up method calls it, if the onEvent parameter is used, which we don’t do.

Steps to reproduce

This error is not thrown on every run, which makes it hard to reproduce. Here is the code snippet of the pulumi up command:

        await stack.up({
            onOutput: (message: string) => process.stdout.write(message)
        })

Affected feature

Automation API for nodejs

About this issue

  • Original URL
  • State: open
  • Created 3 years ago
  • Reactions: 7
  • Comments: 43 (14 by maintainers)

Commits related to this issue

Most upvoted comments

I keep getting this every now and then on github action Node 18.x Pulumi action v3.51.0

Hitting this with preview on github action. No issues when running preview locally from laptop. It is causing preview to hang.

Hitting this one running preview from GHA:

Python: 3.9.10
Action: pulumi/actions@v3.18.1

Does not hang, after a while it goes on (seems normally).

Actually jq was lying at me there are a lot of invalid lines in the file.

while read line; do if ! echo "$line" | jq >/dev/null; then echo "$line"; fi; done < eventlog.txt

Which reveals

arse error: Invalid numeric literal at line 1, column 183
{"sequence":0,"timestamp":1622149849,"diagnosticEvent":{"prefix":"u003c{%reset%}u003edebug: u003c{%reset%}u003e","message":"u003c{%reset%}u003eAWS Auth provider used: "StaticProvider"u003c{%reset%}u003en","color":"raw","severity":"debug"}}
...

There are unescaped quotes " in there.

@rustrial Are you on the community slack? If not, you can email me at komal at pulumi dot com

There are no other runs/tests in parallel currently. We run pulumi login --local first and use the Automation API afterwards. Here is everything that is executed before the error is thrown:

let stack = await LocalWorkspace.createStack({
    stackName: this.stackName,
    workDir: this.config?.dir || process.cwd() + "/tests",
}, {
    envVars: {
        PULUMI_CONFIG_PASSPHRASE: ...,
    },
})

await stack.setConfig("azure:location", {
    value: this.config?.azureLocation || "westeurope",
})

await stack.preview({
    onOutput: (message: string) => process.stdout.write(message)
})

await stack.up({
    onOutput: (message: string) => process.stdout.write(message)
})