losvedir

losvedir

Exact SIGTERM release shutdown behavior and exit signal behavior

Hi everyone. I’m trying to understand some error messages that occasionally appear in our logs durning shutdown. Mostly, I’m just trying to use them to understand the shutdown process a bit better, and trapping exit signals, and all that. When the logs appear, there’s typically about ~10 of them, that look like this:

12/20/2023 7:17:21.434 PM +0000 Last message: {:EXIT, #PID<0.28018.0>, :killed}
      19:17:21.434 [][error] GenServer #PID<0.28046.0> terminating ** (stop) killed

They appear ~7 seconds after I see the long that our release received the SIGTERM and is shutting down. There’s a lot of info in that message, and I’m trying to use it to build a mental model of what’s going on.

From using a remote shell prior to the shutdown and dumping the PIDs and process info, I can see that 0.28018.0 is a supervisor3 and 0.28046.0 is a brod_producer that’s linked to it, both of which come from the brod kafka library we use. The kafka topic this is listening to has 64 partitions, so the supervisor has 64 children, though we typically only get log messages from a handful of them.

So what does Last message: {:EXIT, #PID<0.28018.0>, :killed} mean? I believe this means that:

  • the child, the brod_producer is trapping exits
  • It’s linked to the supervisor, so it receives the supervisor’s exit signals as well.
  • The supervisor received a kill signal (e.g. Process.exit(sup, :kill)), which gets turned into a :killed reason when it propagates.

Question 1:: What does it mean that this was the “last message” that it received? Does it mean it was in the process of handling it? That the message was what caused the GenServer to crash? That it was the last one received and hence the last one in its message inbox, and yet to be processed? That it may have finished handling the message and not gotten any new messages since then?

Question 2: That last message is of the form: {:EXIT, from, reason}. Does that get handled just like any ordinary handle_info? The GenServer terminate/2 won’t handle it, right?

Now, for the other part of the log:

[error] GenServer #PID<0.28046.0> terminating ** (stop) killed

This is the child reporting that it got killed.

Question 3: What are the pieces of those log messages? Is stop or killed the exit reason? Can someone identify what code emits that message and why? Does it indicate the process threw an error? That it was brutal killed? From a brief exploration it looked like that came from formatting a SASL error log or something like that, but I can’t seem to get the message to appear in my local experiments.

Question 4: If that’s in response to an exit signal, do we know what sent it that signal?

I know that normally in a clean shutdown, the supervisor will be told to stop, it will in turn try to stop all its children (in reverse order) with something like GenServer.stop/3, giving 5 seconds (by default, or whatever the shutdown value is in the child_spec), and then it will kill it with something like Process.exit(pid, :kill). But in my example here, it looks like the Supervisor itself was killed prior to this, and that the GenServer trapped that exit, so I’m thinking it’s something else that killed it.

Question 5: When a release receives a SIGTERM, I think that turns into an Application.stop/1 - does that send exit signals beyond simply telling Supervisor.stop/3 to the root supervisor of the application? If the shutdown “hangs” by a misbehaving worker process somewhere, is there a second round of brutal kills that is sent?

The brod kafka library we use has a README with a nice process diagram of how it’s setup. What’s odd about it (and maybe not so standard-OTP?) is the process tree has a client at the top, which is a worker, which manages two children which are supervisors. So my hypothesis is that the application is not shutting down cleanly, because the client worker process at the root of the brod tree is being given 5 seconds to stop, but it then tries to stop its children (which are supervisors) and are taking longer than 5 seconds. So then the application kills the client, which leaves the rest of the tree in a bad state. But I can’t quite tie all the pieces together in my mind yet.

I’d appreciate any help from an expert on OTP practices and how exit signals propagate and all that. Thanks!

First Post!

the_wildgoose

the_wildgoose

In the first instance, drop into an IEX console and run Application.stop or otherwise terminate your application tree. Observe what happens and how long it takes?

Where Next?

Popular in Questions Top

baxterw3b
Hi guys, i’m new in the Elixir world, and i have to say, that i love it! i’m having some problem to understand anonymous functions with ...
New
shahryarjb
Hello, I have map which I want to convert it to string like this: the map: %{last_name: "tavakkoli", name: "shahryar"} the string I ne...
New
ovidiubadita
Hey all, I discovered Elixir and I love it. I always wanted to learn a functional programming and I intended to go for Haskell, but afte...
New
pmjoe
I have a relationship of love and hate with Elixir. Lots of things are just absolutely right, but there are some things that are kind of ...
New
Qqwy
Original source of discussion: This topic on the Pragmatic Programmers’ Functional Web Development with Elixir, OTP, and Phoenix forum. ...
New
vrod
I am using the Starship cross-shell prompt – it seems pretty nice, but I get some errors: [WARN] - (starship::utils): Executing command ...
New
vonH
When I run the Plug and I recompile I wind up having to use Ctrl C to quit iex and start again. Witht the help of rlwrap I can use the cu...
New
RisingFromAshes
I’ve read in another post that it may be possible with a router helper - but I couldn’t find an appropriate one, and tbh, I’m still just ...
New
dotdotdotPaul
Okay, I’m having a heck of a time trying to figure out how to best handle the validation of belongs_to associations in Ecto. I’m sure I’...
New
openscript
Hello! Sorry for this astonishing simple question, but I’m really stuck. I try to set up the intellij-elixir plugin, but I don’t know ho...
New

Other popular topics Top

senggen
Erlang/OTP 25 [erts-13.2.2] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] 15:22:35.803 [error] gen_event {lager_file_backend...
New
chrismccord
As promised, the first release candidate of Phoenix 1.3.0 is out! This release focuses on code generators with improved project structure...
New
skosch
To my knowledge, put_in, Map.update etc. all have the one limitation of not automatically creating intermediate keys when needed (for exa...
New
pmjoe
I have a relationship of love and hate with Elixir. Lots of things are just absolutely right, but there are some things that are kind of ...
New
jay1
Why is it that the mnesia database isn’t the most preferred database for use in Elixir/Phoenix?
New
joeerl
Hello again - after a longish gap I’ve decided I really must dig into Elixir and see what’s been happening here - so I have a few questio...
New
aalberti333
As the title describes, I’m trying to run Enum.map() over a list of key/value pairs, where the value is a map. My data looks like this: ...
New
klo
Got a question about when to concat vs. prepending items to list then reversing to achieve appending. So i know lists boil down to [1 | ...
New
joaquinalcerro
Hi there, I am working with Ecto-Postgresql and I need to call all of the records from a specific table but the table has 40,000 records...
New
openscript
Hello! Sorry for this astonishing simple question, but I’m really stuck. I try to set up the intellij-elixir plugin, but I don’t know ho...
New

We're in Beta

About us Mission Statement