elixir-lang / gen_stage

Producer and consumer actors with back-pressure for Elixir
http://hexdocs.pm/gen_stage
1.51k stars 192 forks source link

Log a warning on a bad subscription #274

Closed axelson closed 3 years ago

axelson commented 3 years ago

Currently when you try to subscribe to a process that is not alive, the error that is printed out does not tell you what process is not alive. Rectify this by adding an additional log statement to cover this case. This will help a developer figure out why their GenStage is not starting and is especially helpful in the case that a Consumer is subscribing to multiple different producers.

This PR is inspired because I had a typo in my subscribe_to that was difficult to track down (okay, actually I had multiple typos at different times)

Example log without this change (code is based on Concurrent Data Processing in Elixir):

22:38:04.691 [info]  PageProducer init
22:38:04.693 [info]  OnlinePageProducerConsumer init
22:38:04.694 [info]  PageProducer received demand for 1 pages
22:38:04.694 [info]  PageConsumerSupervisor init
22:38:04.694 [info]  Application scraper exited: Scraper.Application.start(:normal, []) returned an error: shutdown: failed to start child: PageConsumerSupervisor
    ** (EXIT) no process: the process is not alive or there's no process currently associated with the given name, possibly because its application isn't started
22:38:04.701 [info]  Application gen_stage exited: :stopped
** (Mix) Could not start application scraper: Scraper.Application.start(:normal, []) returned an error: shutdown: failed to start child: PageConsumerSupervisor
    ** (EXIT) no process: the process is not alive or there's no process currently associated with the given name, possibly because its application isn't started

From this error we can tell that PageConsumerSupervisor did not start up properly, but we can't tell what process it was trying to subscribe to that it was not able to access, and it isn't necessarily clear that it failed because it wasn't able to subscribe to a process.

With this change the error looks like:

22:54:10.840 [info]  PageProducer init
22:54:10.843 [info]  OnlinePageProducerConsumer init
22:54:10.843 [info]  PageProducer received demand for 1 pages
22:54:10.843 [info]  OnlinePageProducerConsumer init
22:54:10.843 [info]  PageProducer received demand for 1 pages
22:54:10.843 [info]  PageConsumerSupervisor init
22:54:10.844 [error] GenStage consumer PageConsumerSupervisor was not able to subscribe to the process {:via, Registry,
 {:producer_consumer_registry, "online_page_producer_consumer_1"}} because that process is not alive

22:54:10.851 [info]  Application scraper exited: Scraper.Application.start(:normal, []) returned an error: shutdown: failed to start child: PageConsumerSupervisor
    ** (EXIT) no process: the process is not alive or there's no process currently associated with the given name, possibly because its application isn't started
22:54:10.855 [info]  Application gen_stage exited: :stopped
** (Mix) Could not start application scraper: Scraper.Application.start(:normal, []) returned an error: shutdown: failed to start child: PageConsumerSupervisor
    ** (EXIT) no process: the process is not alive or there's no process currently associated with the given name, possibly because its application isn't started

I believe this is an improvement because it helps the developer understand that the error is because a process that the consumer is trying to subscribe to is not alive, and specifically which of those processes is not alive.

Another way to solve this might be to return more information than just :noproc, but from what I can tell that would require a change to Elixir itself (probably around https://github.com/elixir-lang/elixir/blob/f7a8ffd0a614de23661a7552fdb6b0a6dc66e151/lib/elixir/lib/exception.ex#L396), which seems untenable because it would take a long time until gen_stage could depend on a newer version of Elixir. Also this wouldn't make it clear that it was a consumer that was trying to subscribe.

josevalim commented 3 years ago

:green_heart: :blue_heart: :purple_heart: :yellow_heart: :heart:

axelson commented 3 years ago

Thanks!