Debugging obscure process crashes?

UPDATE: I’m getting tons of Postgrex.Protocol client exits, not sure what’s going on – the local server seems to completely crash and hangs all requests.

I’m not doing any particularly long-running queries. Is there any way to get further stacktraces for these exits?

I believe I’ve found the cause of the request stalls: Postgrex is exiting in the client.

SELECT count('*') FROM (SELECT se0."id" AS "id" FROM "events" AS se0 LEFT OUTER JOIN "subscribers" AS ss1 ON ss1."id" = se0."subscriber_id" WHERE (ss1."user_id" = $1) LIMIT $2) AS s0 [1, 10001]
[info] Sent 200 in 41ms
[info] Postgrex.Protocol (#PID<0.548.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.9955.4> exited

Not sure what’s causing it. A Google search says there might be trouble with some plugs. I’ll check my scustom plugs and see if I’m doing anything crazy.

They are called live reloads.

Okay, thanks! The next big question is debugging why requests start stalling under load, but I figure that might be related to Postgres.

No, the whole VM is unloading the code that was there before, and then loading the new compiled code. The best thing to do is just let Oban retry the job after the crash.

In that case, is there any way to exclude Oban from hot reloads?

Gotcha, yeah I mean with development reloads crashes of background processes are pretty normal, code is getting loaded and unloaded without regard for whether there are live processes using that code. If that’s the only time this is happening I wouldn’t worry about it.

Fixed up! I meant development hot reloads, yes.

Hey @mattei as a couple of notes, please always copy and paste text instead of using screenshots. Those screenshots are barely visible on my screen due to resolution / saturation.

Secondly, when you say “hot reloads” are you referring to development code reloading, or are you using OTP hot reloading in production?

I suspect I found the problem. I strongly believe related to hot-reloads with Phoenix.

I came back from sleep (long-running session) and triggered two consecutive hot reloads in the dev server. Jobs started getting killed, and thanks to @cmo’s logging snippet I started seeing this error pop up:

[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19581.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19582.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19584.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19583.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19586.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19592.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19587.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19574.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19585.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19575.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19577.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19591.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19588.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19578.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19589.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[error] Child :undefined of Supervisor {Oban.Registry, {Oban, {:foreman, "default"}}} terminated
** (exit) killed
Pid: #PID<0.19590.7>
Start Call: Task.Supervised.start_link/?
Restart: :temporary
Shutdown: 5000
Type: :worker
[info] {"args":{"endpoint_id":2,"event_id":25439},"attempt":5,"duration":243090,"error":"** (exit) killed","event":"job:exception","id":127098,"max_attempts":10,"meta":{},"queue":"default","queue_time":2513829,"source":"oban","state":"failure","tags":[],"worker":"Parcel.Jobs.Deliver"}

I’m still working to nail down a true path to replicate, but this is a good step – there’s a trace.

Will file an issue in @sorentwo’s Oban repo once I can find a way to replicate.