Help diagnosing an intermittent Elixir bug - updating matches within conditionals (if, cond, case)

I have an Elixir function that is intermittently and repeatedly failing at a particular point. I have used Logger.info for tracing and it really does seem to be independent from the input I am supplying it. I keep running it with the same input and sometimes it fails and sometimes it doesn’t. From my reading of my coding, it shouldn’t fail - But that’s bugs for you.

I have just recently upgraded from a much older version of Elixir and learned I needed to fix the error of my ways re. expecting to be able to update matches (variables) from within conditional scope (if, cond, case) so have necessarily done a lot of code changes to what was previously working well.

Background:
Stack
Erlang/OTP 22 [erts-10.6.1] [source] [64-bit] [smp:1:1] [ds:1:1:10] [async-threads:1]
Elixir 1.9.4 (compiled with Erlang/OTP 21)
Ubuntu (Linux alived02 4.9.0-4-amd64 #1 SMP Debian 4.9.65-3+deb9u1 (2017-12-23) x86_64 GNU/Linux)
Google Cloud Platform.

The Code

Logger.info(" TRACING  sectionRelBarNumber:0 spliceHoldsList:  -  Before Bang ")

#Bang!
{anInt, aList, aMap} = 
if (anotherInt > 0)  do

   # a lot of very similar if then else end code
   # reassignment / rematching of anInt,  aList and aMap.

   {anInt, aList, aMap}
else
   Logger.info("here")
  # reassignment / rematching of anInt,  aList and aMap.

   {anInt, aList, aMap}
end

I intermittently get an abort here with these diag’s -

11:40:17.528 request_id=FeT_PlajpEh9RngAAAFh [error] buildSection(): TRACING  sectionRelBarNumber:0 spliceHoldsList:  -  Before Bang 
11:40:17.583 request_id=FeT_PlajpEh9RngAAAFh [info] Sent 500 in 4888ms
11:40:17.596 request_id=FeT_PlajpEh9RngAAAFh [info] Converted error {:badmatch, nil} to 500 response
11:40:17.684 [error] Ranch listener IfSfrt.Endpoint.HTTP, connection process #PID<0.473.0>, stream 1 had its request process #PID<0.474.0> exit with reason {{%MatchError{term: nil}, [{GenSFRT.GenerateSplits, :buildSection, 7, [file: 'lib/gen_
sfrt/gen_splits.ex', line: 1733]}, {GenSFRT.GenerateSplits, :genSection, 5, [file: 'lib/gen_sfrt/gen_splits.ex', line: 2106]}, {GenSFRT.GenerateSplits, :genSplitsAndMerge, 3, [file: 'lib/gen_sfrt/gen_splits.ex', line: 2759]}, {GenSFRT.CreateS
FRT, :legacyBuildAudioFile, 8, [file: 'lib/gen_sfrt/createSFRT.ex', line: 496]}, {GenSFRT.CreateSFRT, :createSFRT, 2, [file: 'lib/gen_sfrt/createSFRT.ex', line: 1182]}, {IfSfrt.PageController, :download, 2, [file: 'web/controllers/page_contro
ller.ex', line: 51]}, {IfSfrt.PageController, :action, 2, [file: 'web/controllers/page_controller.ex', line: 1]}, {IfSfrt.PageController, :phoenix_controller_pipeline, 2, [file: 'web/controllers/page_controller.ex', line: 1]}]}, {IfSfrt.Endpo
int, :call, [%Plug.Conn{adapter: {Plug.Cowboy.Conn, :...}, assigns: %{}, before_send: [], body_params: %Plug.Conn.Unfetched{aspect: :body_params}, cookies: %Plug.Conn.Unfetched{aspect: :cookies}, halted: false, host: "fileapi.alive-drumming.o
rg", method: "GET", owner: #PID<0.474.0>, params: %Plug.Conn.Unfetched{aspect: :params}, path_info: ["6x12BB_4E", "6x12BB_4EBluesShuffle%5EDRY100Variation3Of7_AllMix.mp3"], path_params: %{}, port: 8003, private: %{}, query_params: %Plug.Conn.
Unfetched{aspect: :query_params}, query_string: "", remote_ip: {37, 0, 49, 117}, req_cookies: %Plug.Conn.Unfetched{aspect: :cookies}, req_headers: [{"accept", "*/*"}, {"accept-encoding", "gzip, deflate"}, {"accept-language", "en-us"}, {"conne
ction", "keep-alive"}, {"host", "fileapi.alive-drumming.org:8003"}, {"user-agent", "SongFormRhythmTracks/7.2.1 CFNetwork/978.0.7 Darwin/18.6.0"}], request_path: "/6x12BB_4E/6x12BB_4EBluesShuffle%5EDRY100Variation3Of7_AllMix.mp3", resp_body: n
il, resp_cookies: %{}, resp_headers: [{"cache-control", "max-age=0, private, must-revalidate"}], scheme: :http, script_name: [], secret_key_base: nil, state: :unset, status: nil}, []]}} and stacktrace [{Phoenix.Endpoint.Cowboy2Handler, :init,
 4, [file: 'lib/phoenix/endpoint/cowboy2_handler.ex', line: 59]}, {:cowboy_handler, :execute, 2, [file: '/home/matthew_hargreaves/AD_SFRT_Generator/elixir/if_sfrt/deps/cowboy/src/cowboy_handler.erl', line: 41]}, {:cowboy_stream_h, :execute, 3
, [file: '/home/matthew_hargreaves/AD_SFRT_Generator/elixir/if_sfrt/deps/cowboy/src/cowboy_stream_h.erl', line: 320]}, {:cowboy_stream_h, :request_process, 3, [file: '/home/matthew_hargreaves/AD_SFRT_Generator/elixir/if_sfrt/deps/cowboy/src/c
owboy_stream_h.erl', line: 302]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]

The diagnosed line, …gen_splits.ex’, line: 1733, is the line
{anInt, aList, aMap} =

I think the diagnostic is "{{%MatchError{term: nil}, " but I know that none of the three are ‘nil’ at the point in the code.

Could I be hitting resource limits? What would best way to diagnose this further? I am running out of ideas.

Appreciate any help anyone has. Thanks.

Matt

1 Like

Hi @mattharg, it’ll be a lot easier to help you if you can do a few things:

  1. Format your forum code. As written it’s extremely hard to read, and this makes it hard to help you.
  2. Provide the full and complete code. It seems like you’re summarizing with stuff like “a lot of very similar if then else end code”. Bugs are always about details, and summaries like this hide those details, and make it hard to follow the flow of the code. Based on line: 1733 it seems like the file is extremely long, so I’d consider using pastebin or gist.
  3. Not a thing for the moment, but you’ll want to improve your variable names, anInt doesn’t make it clear what its purpose is. Maybe this is a summary too though?

Based on the fact that you got a stack trace, your bug is a good old fashioned exception. You mention that you upgraded from an earlier Elixir version, so what’s probably happening is this:

a = 1
b = if some_conditional do
  a = 2
  :foo
else
  :bar 
end

The above no longer works. The change to a acted like an implicit rebind, which was removed. To get the same behaviour in newer versions of Elixir you need to make the rebind explicit:

a = 1
{b, a} = if some_condition do
  {:foo, 2}
else
  {:foo, a}
end

This is probably the source of your issues, but without being able to look at your code, I can’t be of further help

3 Likes

It seems as if you made a very huge jump from one version to the other.

Updating variable bindings from within an if gave a warnings for many years. Either you have ignored the warnings and shoot yourself in the foot now, or you updated from 1.2ish to 1.8ish without any steps in-between.

You really should update your version not more than 2 minors at a time, as that’s the span of a deprecation cycle.

Fixing occuring warnings on sight.

Doing the upgrade in such small steps should point out all the “imperative assignments” you made through out your code.

2 Likes

Try updating cowboy (and everything that dependency update demands)

EDIT: update to the newest version
Updating can be a pain in the ass - the best way of going through this is going through dependency updates and try to pinpoint what else you need to update.

1 Like

Thanks. Yes, that clears things up - being explicit about the rebinds now. BTW, I got over the intermittent nature of the fault by updating cowboy and other dependencies. I didn’t want to share the entire function as it’s got way too large with too many nested conditionals and now more so with the explicit rebinds. It’s time to refactor. Thanks so much for the advice.

Thanks. Yes, lesson learnt. Huge jump and taking heed of all the warnings has been the easiest way to fix this. I guess I just wasn’t ready to shake off that particular bit of imperative thinking until I was forced to.

Thanks. Updating all my dependencies, including cowboy, did fix the intermittent nature and allowed me to focus on the real issue. Cheers.