Coroutine not using configured logger

Question

While launching a coroutine in a certain way I noticed that, when it fails, it does not use the configured Log4j logger to log the exception, but rather does it to the stderr. Despite being far from a real-world scenario, the below represents the minimal reproducible snippet to showcase the problem.

@RestController
class SoDemoController {
    @GetMapping("/demo")
    fun demo(): ResponseEntity<String> {
        CoroutineScope(Dispatchers.Default).launch {
            async {
                // Something useful is done here
                delay(1000)
                error("some error happens")
            }.await()
        }

        return ResponseEntity.ok("done")
    }
}

Output:

Exception in thread "DefaultDispatcher-worker-3" java.lang.IllegalStateException: some error happens
...

Now, using runBlocking for some reason solves the problem.

@RestController
class SoDemoController {
    @GetMapping("/demo")
    fun demo(): ResponseEntity<String> {
        runBlocking {
            async {
                // ... rest of the code ...

Output:

2024-04-13T14:08:36.091+01:00 ERROR 5771 --- [demo] [nio-8080-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: java.lang.IllegalStateException: some error happens] with root cause

While I understand the behavior between runBlocking and CoroutineScope.launch is different in the sense that one blocks the thread and the other one, as it stands, it's fire and forget, I don't quite understand how it affects the channel through which the log is done (stderr vs log4j).

What is the reason behind this difference and what would be the best way to solve it? The debate about using runBlocking or not is confusing at times and I'm not sure if there's a better approach in this scenario.

Answer 1

These two cases are much different.

If using runBlocking, demo function waits for the coroutine to finish. If coroutine fails, the exception is thrown from the demo function. That results in the 500 error, Spring knows about the exception and logs it according to its config.

If using launch, coroutine is launched in the background, demo returns successfully, and Spring doesn't even know there's some task running in the background. Task is managed by the coroutine framework, not by Spring. If the coroutine fails, then again, Spring doesn't even know about it. Error is logged by the coroutine framework and of course, coroutines know nothing about the Spring and its logging config. Coroutines machinery logs the message according to its default behavior which is printing to stderr.

If you like to change the way how errors in coroutines are handled, you can provide a CoroutineExceptionHandler as explained here: https://kotlinlang.org/docs/exception-handling.html#coroutineexceptionhandler

Few notes about your coroutine code:

• Such fire and forget behavior is generally discouraged. One reason is... well, that errors happening in the background are ignored.
• If you really need a fire and forget behavior, you can use GlobalScope instead of CoroutineScope(Dispatchers.Default). It does a similar thing, but is more clear on the fact the coroutine is detached.
• async { ... }.await() doesn't make too much sense. You can remove it and keep the ... code only.