Debugging an unexpected process exit

Questions / Help
, ,
1

Hi friends,

I’m working on a contribution to Finch and am having a hell of a time debugging an unexpected process exit that’s causing a test to fail.

The code being tested is rather unfinished and very much a work-in-progress, but I wanted to have a baseline before I start refactoring and moving things around. When the test reaches the call to cancel the async request, the test fails (not immediately, but after a very small period), with the following message:

image
image857×263 15.3 KB

Things I’ve tried so far:

  • Re-creating the issue without using Finch (I couldn’t)
  • Running the code outside of the context of a test (it works as expected)
  • Creating the process with a Task supervisor (what’s currently in the code)
  • Creating the process with Task.async
  • Creating the process with spawn
  • Various exit trapping

I have a hunch this has something to do with ExUnit’s GenServer, but I’m really struggling to find more information and I’m at a loss for how to debug further.

1 Like
2

The message looks a lot like the symptom from this issue:

This could be happening when the Task terminates while still waiting for a reply from Bypass, causing the Bypass process to crash and taking the test process down along with it.

You could try trapping exits in the test and calling receive explicitly to see what’s bubbling up.

Another thing to try: add a sleep for longer than the sleep in the Bypass.expect block to the very end of the test, so that the Bypass process is definitely finished before the test ends.

3 Likes
3

That looks really promising. I cloned Bypass and changed the dep to a local path-based one and then tried fixing the line referenced in that issue and removing it altogether, both to no avail. It does seem likely that it’s taking down the Bypass server somehow.

4

Maybe sys debug can help? Debug tracing · Elixir Recipes

1 Like
5

That was a good idea.

......................................self: #PID<0.1343.0>
bypass: #PID<0.1344.0>
async req pid: #PID<0.1360.0>
finch: #PID<0.1357.0>
*DBG* <0.1344.0> got {'DOWN',#Ref<0.1067949558.531890179.24259>,process,
                             <0.1363.0>,shutdown}
*DBG* <0.1344.0> new state #{callers_awaiting_down => [],
                             callers_awaiting_exit => [],
                             expectations =>
                                 #{{any,any} =>
                                       #{expected => once_or_more,
                                         'fun' =>
                                             #Fun<Elixir.FinchTest.1.116636333>,
                                         path_parts => [],request_count => 1,
                                         results =>
                                             [{exit,{exit,shutdown,[]}}],
                                         retained_plugs => #{}}},
                             monitors => #{},pass => false,port => 43377,
                             ref => #Ref<0.1067949558.531890179.24222>,
                             socket => #Port<0.203>,
                             unknown_route_error => nil}
*DBG* <0.1344.0> got call on_exit from <0.1364.0>
*DBG* <0.1344.0> sent {exit,{exit,shutdown,[]}} to <0.1364.0>, new state #{callers_awaiting_down =>
                                                                            [],
                                                                           callers_awaiting_exit =>
                                                                            [],
                                                                           expectations =>
                                                                            #{{any,
                                                                               any} =>
                                                                               #{expected =>
                                                                                  once_or_more,
                                                                                 'fun' =>
                                                                                  #Fun<Elixir.FinchTest.1.116636333>,
                                                                                 path_parts =>
                                                                                  [],
                                                                                 request_count =>
                                                                                  1,
                                                                                 results =>
                                                                                  [{exit,
                                                                                    {exit,
                                                                                     shutdown,
                                                                                     []}}],
                                                                                 retained_plugs =>
                                                                                  #{}}},
                                                                           monitors =>
                                                                            #{},
                                                                           pass =>
                                                                            false,
                                                                           port =>
                                                                            43377,
                                                                           ref =>
                                                                            #Ref<0.1067949558.531890179.24222>,
                                                                           socket =>
                                                                            nil,
                                                                           unknown_route_error =>
                                                                            nil}


  1) test async_request/3 with HTTP/1 can be canceled with cancel_async_request/2 (FinchTest)
     test/finch_test.exs:771
     ** (exit) shutdown

................................
Finished in 7.3 seconds (5.0s async, 2.2s sync)
71 tests, 1 failure

Randomized with seed 853761

So it looks like Bypass is sending an exit shutdown message to what I presume to be the test server. I’m not entirely sure why or what I can do to prevent it.

Edit: Looking at the code, it’s Bypass that’s exiting here.

Edit 2: And, indeed, if I modify Bypass to not exit at that line, the test works.

3 Likes