ActiveJob AsyncAdapter swallows exceptions, doesn't log by default

[sbull]

(On Rails 5.0.0.1)

Using the default AsyncAdapter in development, I was disappointed that I didn't see errors from my jobs even though I knew they were throwing exceptions (undefined methods, etc.). I would see the following messages in my log:

INFO -- : [ActiveJob] Enqueued MyJob ... (Job ID: f071893e-be9a-44fd-810c-5b38b270c58c) to Async(mail)...
... <snip> ...
INFO -- : [ActiveJob] [MyJob] [f071893e-be9a-44fd-810c-5b38b270c58c] Performing MyJob from Async(mail)...
INFO -- : [ActiveJob] [MyJob] [f071893e-be9a-44fd-810c-5b38b270c58c] Performed MyJob from Async(mail)

If I set the following in an initializer:

Concurrent.global_logger = Concurrent.create_stdlib_logger(Logger::DEBUG)

I get the errors printed on my terminal (not in log/development.log). I believe this is due to the logic in Concurrent::RubyThreadPoolExecutor::Worker#run_task.

It seems like with AsyncAdapter being the new development default, there should be something that notifies developers of job errors in the default setup. At least, perhaps an initializer that sets the Concurrent logger according to other Rails logger settings? But it might also be ideal for ActiveJob not to record "Performed MyJob", and instead say something like "Failed MyJob"

[maclover7]

cc @jdantonio

[jdantonio]

This is expected behavior, but the suggested change is fairly easy. Please see PR #26852.

Application level exception handling is not a responsibility of Concurrent::ThreadPoolExecutor. Thread pools are low level abstractions. With respect to exception handling, the thread pool's only responsibility is to protect the integrity of the pool. Since unhandled exceptions in Ruby crash threads, Concurrent::ThreadPoolExecutor catches all exceptions not caught by the job proc and suppresses them, ensuring the continued operation of the thread. This is basic thread pool behavior and will probably never change.

High level abstractions in concurrent-ruby all provide robust error handling and reporting features by passing a job wrapper to the thread pool. Concurrent.global_logger is used by some of the high level abstractions (like Actor) but not by all. It is not used directly by the thread pool ever. Changing Concurrent.global_logger will have no effect on any thread pool.

With respect to AsyncAdapter, exception handling was never part of the initial implementation since it was intended to only be used for testing only. Adding the suggested behavior will require a small update to the JobWrapper in AsyncAdapter.

[sbull]

@jdantonio: Your PR looks like it addresses my problem - I should be able to see what's going wrong now when using the default development settings. I also think it's good for the exceptions to show up in the test logs, as it looks like they will (to your point about AsyncAdapter originally intended only for testing) - that will probably save some headaches.

I agree that monkeying with things in concurrent-ruby to address this is non-ideal, though it might be nice to be able to easily route concurrent-ruby's logs to Rails' logs with some Rails config setting - I'm not sure what else concurrent-ruby is used for in Rails, or if simplifying the log management would be helpful now or in the future. At the moment, it's easy enough to set Concurrent.global_logger in a Rails initializer, but it took some digging to figure out how to do that. I'm guessing this is not something you're interested in addressing (and likely shouldn't be a part of this PR).

The only remaining detail that I had was if there is a way for the AJ logging to say something different than "Performed", but it doesn't look like that's an option. "Performed" appears to be used by all adapters, regardless if there is an exception in the perform method. Curiously though, I'm wondering if the :inline adapter should mimic :async's behavior and swallow exceptions around perform rather than bubble them up to the caller. But this would be a change in :inline's behavior, so I suppose there should be a new adapter if you want to run jobs inline (serially with the enqueuing code) but continue execution if the job throws an exception. Perhaps not an important use case.