TerminalError stacktrace reconstruction during replay can result into journal mismatch

[MohamedBassem]

Context

I have a handler logic that roughly looks something like this:

    // Call the runner service
    const res = await tryCatch(runner.run(jobData));

    // Handle RPC-level errors (e.g., runner service unavailable)
    // ...
    if (res.error instanceof restate.CancelledError) {
      throw res.error;
    }
    // Notify the runner of the RPC error
    await tryCatch(
      runner.onError({
        job: jobData,
        error: {
          name:
            res.error instanceof Error ? res.error.name : "RPCError",
          message: res.error instanceof Error ? res.error.message : String(res.error),
          stack:
            res.error instanceof Error ? res.error.stack : undefined,
        },
      }),
    );

The handler calls a restate service, and if it hits any exceptions, it calls another service with the details about this error (name, message and stacktrace). The main assumption here is that during replay, the error details are going to be deterministic.

Problem

When the main service handler fails with terminal error(e.g: network error, the service is unavailable), this seems to result into a mismatch into the journal entry caused by a mismatch in the stack trace returned during replay:

[570] Found a mismatch between the code paths taken during the previous execution and the paths taken during this execution.
This typically happens when some parts of the code are non-deterministic.
- The mismatch happened while executing 'call' (index '14')
- Difference:
   parameter: '{"job":{"id":"inv_1bDIFRtrYMPl0DXqSC9RamS0cM5c2nXNe1","data":{"bookmarkId":"ft760zlpdg46o1n49e2cg0vz"},"priority":50,"runNumber":0,"numRetriesLeft":5,"timeoutSecs":60},"error":{"name":"TerminalError","message":"unexpected error while reading the response body: error reading a body from connection","stack":"TerminalError: unexpected error while reading the response body: error reading a body from connection\n    at Failure (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:421:15)\n    at RestateSinglePromise.completer (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:380:50)\n    at runNextTicks (node:internal/process/task_queues:65:5)\n    at process.processImmediate (node:internal/timers:472:9)\n    at async RestateSinglePromise.tryComplete (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:73:3)\n    at async PromisesExecutor.doProgressInner (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:197:4)\n    at async <anonymous> (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:216:5)"}}' != '{"job":{"id":"inv_1bDIFRtrYMPl0DXqSC9RamS0cM5c2nXNe1","data":{"bookmarkId":"ft760zlpdg46o1n49e2cg0vz"},"priority":50,"runNumber":0,"numRetriesLeft":5,"timeoutSecs":60},"error":{"name":"TerminalError","message":"unexpected error while reading the response body: error reading a body from connection","stack":"TerminalError: unexpected error while reading the response body: error reading a body from connection\n    at Failure (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:421:15)\n    at RestateSinglePromise.completer (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:380:50)\n    at async RestateSinglePromise.tryComplete (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:73:3)\n    at async PromisesExecutor.doProgressInner (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:197:4)\n    at async <anonymous> (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:216:5)"}}'

Where the calls are the following:

After beautifying the stacks:

  Original execution:
  TerminalError: unexpected error while reading the response body: error reading a body from connection
      at Failure (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:421:15)
      at RestateSinglePromise.completer (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:380:50)
      at runNextTicks (node:internal/process/task_queues:65:5)          ← EXTRA
      at process.processImmediate (node:internal/timers:472:9)          ← EXTRA
      at async RestateSinglePromise.tryComplete (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:73:3)
      at async PromisesExecutor.doProgressInner (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:197:4)
      at async <anonymous> (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:216:5)

  Replay execution:
  TerminalError: unexpected error while reading the response body: error reading a body from connection
      at Failure (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:421:15)
      at RestateSinglePromise.completer (/app/node_modules/@restatedev/restate-sdk/dist/context_impl.js:380:50)
      at async RestateSinglePromise.tryComplete (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:73:3)
      at async PromisesExecutor.doProgressInner (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:197:4)
      at async <anonymous> (/app/node_modules/@restatedev/restate-sdk/dist/promises.js:216:5)

Notice how the original execution contained some node internal frames, while the replay didn't.

It seems that the SDK doesn't store in the journal the stacktraces of terminal failures (only code and message) and instead attempts to reconstruct them during replay. But this seems like it can be a constant source of indeterminism that it makes me wonder if it's possible for the sdk to nullify it or something to prevent users from shooting themselves in the foot.

Thanks!

Env

Node: 24
Sdk Version: 1.10.3
Server version: 1.6.1

[tillrohrmann]

Thanks a lot for reporting this issue @MohamedBassem. This looks indeed like a footgun. @igalshilman are we regenerating stack traces that could then lead to the non-determinism errors as described by Bassem?

[slinkydeveloper]

I can confirm that indeed now we're not erasing the stacktrace nodes collects everytime we call new TerminalError, thus causing this issue. Let me think how to best solve it, in a way that we can still preserve some good logging experience.

[slinkydeveloper]

Hey @MohamedBassem, we thought this through, and currently we think it's not a good idea to nullify the stack, the reason is that it would hide the stacktrace when logging the event, or when the user passes the error through their own reporting system, expecting the "stack" field to be there.

I'll update the TSDoc to be more explicit about the stack, and the fact that it can be non deterministic.

Related to the code you posted, what is your use case to pass stack through? Why even the code:

          stack:
            res.error instanceof Error ? res.error.stack : undefined,

If we blank the stacktrace, this will always be null anyway.

[MohamedBassem]

Thanks for the response folks!

@slinkydeveloper from my side, I don't mind dropping the stacktrace from my 2nd callsite. My report is mostly about the footgun. Nullifying the stacktrace is just one option, the other would be for example to hide the property behind an accessor that would make it clear that it's non deterministic (e.g. nonDeterminsticStacktrace(), not the most ergonomic name though). I'm just afraid that adding a TSDoc on a commonly used property would still make it easy for people to miss it. I'd have missed it.

I'm also curious if storing the stacktrace for terminal errors would be an option? Retryable errors seems to capture it, and I'm curious why TerminalErrors don't.

[slinkydeveloper]

the other would be for example to hide the property behind an accessor that would make it clear that it's non deterministic (e.g. nonDeterminsticStacktrace(), not the most ergonomic name though).

That's one option we thought through, the problem with this again is when users integrate with their logging libraries, error reporting systems, tracing libraries, etc, using some non-standard stack field will be easy to miss, and doing this at this point could constitute a breaking change for some people.

I'm also curious if storing the stacktrace for terminal errors would be an option? Retryable errors seems to capture it, and I'm curious why TerminalErrors don't.

In retryable error we don't need to rebuild the stacktrace in the user code, we just put it to a string and ship it to the runtime for observability purposes. With terminal errors, we need to rebuild it, and that aspect is not trivial, because stacktraces have different representations depending on the language: in javascript it's a simple string true, but in java for example it's an array of StackTraceElement https://docs.oracle.com/en/java/javase/11/docs/api/java.base/java/lang/StackTraceElement.html, with different fields to fill back in. The problem gets even more complicated when you have a restate service built with language A calling restate service built with language B.

It's solvable, but so far we didn't get any user feedback that is generally a useful feature and worth solving 😄