Add job_id and exception message to ActiveJob retry/discard logging - #42990

I'm sorry I don't understand what to do with that build failure, I think it's unrelated?

I am not familiar with this build system (I think Rails has changed it since I last looked at a Rails CI), but I think maybe actual automated tests were run anyway and green? Not sure.

The error I can find in build output is related to npm/webpacker, and my PR touched nothing related to JS, so.

error @rails/[email protected]: The engine "node" is incompatible with this module. Expected version "^12 \|\| >=14". Got "10.24.1"
--
  | error Found incompatible module.
  | info Visit https://yarnpkg.com/en/docs/cli/install for documentation about this command.
  | ERROR: Service 'base' failed to build: The command '/bin/sh -c mv -f tmp/Gemfile.lock.updated Gemfile.lock     && if [ -f package.json ]; then         echo "--- :javascript: Building JavaScript package"         && (cd actionview && yarn build)         && if [ -f railties/test/isolation/assets/package.json ]; then             (cd railties/test/isolation/assets && yarn install);         fi         && yarn cache clean;     fi' returned a non-zero code: 1
  | 🚨 Error: The command exited with status 1

This pull request has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.
Thank you for your contributions.

I would still love for this to be considered for merge. Will rebase.

This pull request has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.
Thank you for your contributions.

I would still love to see this reviewed/merged, I think it is a pretty simple improvement to ActiveJob logging to make it more internally consistent and predictable. I have had to monkey-patch my own Rails to add it; I think all would benefit from it.

I guess I'm just gonna keep posting that everytime rails bot tries to mark it stale!

Job ID is especially useful because, while other ActiveJob-related log messages get the Job ID via tagged logging, retry-related log messages do not currently end up tagged with Job ID.

I wonder if it would be practical for us to solve it at this layer (i.e., by arranging to tag those log messages). I imagine people who parse and group logs based on tags during ingestion into some log system might prefer that consistency. 🤔

Failure looks real:

https://buildkite.com/rails/rails/builds/82441#1486d9db-ae9c-4aef-9354-c51ae55199a7/1013-1028

Could not log "enqueue_retry.active_job" event. NameError: undefined local variable or method `job_executions' for #<ActiveJob::LogSubscriber:...

Thanks so much for feedback @matthewd !

I have fixed the typo error caught by CI now that it was working! And rebased on main branch -- build is now green!

I wonder if it would be practical for us to solve it at this layer (i.e., by arranging to tag those log messages).

It does sound like a good solution to get ActiveJob logging to automatically tag with "Job ID". it's a bit beyond my knowledge/energy to do that at present.

The logging was already including JobID in some log messages but not others; this PR keeps the same architecture that was there before without adding/changing anything, just makes all log messages consistent with info and formatting. Perhaps that's a reasonable step.

The logging was already including JobID in some log messages but not others

Yep, fair point 👍🏻

Thanks! (And thanks for persevering through the silence)

Thank you @matthewd !