Test fails on OTP 26, Elixir 1.15.0

[dmilith]

Elixir and Erlang/OTP versions

Elixir 1.15.0
OTP 26.0

Operating system

FreeBSD 13.1

Current behavior

The failing test #1:

  1) test runs in daemon mode (Mix.Tasks.ReleaseTest)
     /Software/Elixir/.src_0f0fb73a61d955a5/elixir-1.15.0/lib/mix/test/mix/tasks/release_test.exs:709
     ** (ExUnit.TimeoutError) test timed out after 60000ms. You can change the timeout:

       1. per test by setting "@tag timeout: x" (accepts :infinity)
       2. per test module by setting "@moduletag timeout: x" (accepts :infinity)
       3. globally via "ExUnit.start(timeout: x)" configuration
       4. by running "mix test --timeout x" which sets timeout
       5. or by running "mix test --trace" which sets timeout to infinity
          (useful when using IEx.pry/0)

     where "x" is the timeout given as integer in milliseconds (defaults to 60_000).

     stacktrace:
       (elixir 1.15.0) lib/process.ex:303: Process.sleep/1
       test/mix/tasks/release_test.exs:800: Mix.Tasks.ReleaseTest.wait_until/1
       test/mix/tasks/release_test.exs:743: anonymous fn/1 in Mix.Tasks.ReleaseTest."test runs in daemon mode"/1
       (mix 1.15.0) lib/mix/project.ex:458: Mix.Project.in_project/4
       (elixir 1.15.0) lib/file.ex:1624: File.cd!/2
       test/test_helper.exs:146: MixTest.Case.in_fixture/3
       test/mix/tasks/release_test.exs:710: (test)
       (ex_unit 1.15.0) lib/ex_unit/runner.ex:463: ExUnit.Runner.exec_test/2
       (stdlib 5.0) timer.erl:270: :timer.tc/2
       (ex_unit 1.15.0) lib/ex_unit/runner.ex:385: anonymous fn/5 in ExUnit.Runner.spawn_test_monitor/4

The failing test #2:

  2) test code path prunning (Mix.Tasks.CompileTest)
     /Software/Elixir/.src_0f0fb73a61d955a5/elixir-1.15.0/lib/mix/test/mix/tasks/compile_test.exs:332
     match (=) failed
     code:  assert {:docs_v1, _, _, _, _, _, _} = Code.fetch_docs(:zlib)
     left:  {:docs_v1, _, _, _, _, _, _}
     right: {:error, :chunk_not_found}
     stacktrace:
       test/mix/tasks/compile_test.exs:340: anonymous fn/0 in Mix.Tasks.CompileTest."test code path prunning"/1
       (elixir 1.15.0) lib/file.ex:1624: File.cd!/2
       test/test_helper.exs:146: MixTest.Case.in_fixture/3
       test/mix/tasks/compile_test.exs:335: (test)

Also, I think there's a typo (detected by Grammarly):

"prunning" => "pruning" :)

Expected behavior

On Elixir 1.14.5 the "make -j6 test" went just fine with the same OTP version.

[dmilith]

@josevalim Unfortunately even with OTP built with docs the same test fail happens on MacOS 12.6.6 with the same OTP 26 and Elixir 1.15.0

[dmilith]

An example from macOS 12.6.6:

  1) test runs in daemon mode (Mix.Tasks.ReleaseTest)
     /Users/Shared/Software/Elixir/.src_0f0fb73a61d955a5/elixir-1.15.0/lib/mix/test/mix/tasks/release_test.exs:709
     ** (ExUnit.TimeoutError) test timed out after 60000ms. You can change the timeout:

       1. per test by setting "@tag timeout: x" (accepts :infinity)
       2. per test module by setting "@moduletag timeout: x" (accepts :infinity)
       3. globally via "ExUnit.start(timeout: x)" configuration
       4. by running "mix test --timeout x" which sets timeout
       5. or by running "mix test --trace" which sets timeout to infinity
          (useful when using IEx.pry/0)

     where "x" is the timeout given as integer in milliseconds (defaults to 60_000).

     stacktrace:
       (elixir 1.15.0) lib/process.ex:303: Process.sleep/1
       test/mix/tasks/release_test.exs:800: Mix.Tasks.ReleaseTest.wait_until/1
       test/mix/tasks/release_test.exs:743: anonymous fn/1 in Mix.Tasks.ReleaseTest."test runs in daemon mode"/1
       (mix 1.15.0) lib/mix/project.ex:458: Mix.Project.in_project/4
       (elixir 1.15.0) lib/file.ex:1624: File.cd!/2
       test/test_helper.exs:146: MixTest.Case.in_fixture/3
       test/mix/tasks/release_test.exs:710: (test)
       (ex_unit 1.15.0) lib/ex_unit/runner.ex:463: ExUnit.Runner.exec_test/2
       (stdlib 5.0) timer.erl:270: :timer.tc/2
       (ex_unit 1.15.0) lib/ex_unit/runner.ex:385: anonymous fn/5 in ExUnit.Runner.spawn_test_monitor/4

Unsure what that means since I explicitly set ELIXIR_ASSERT_TIMEOUT=80000

[josevalim]

I fixed the failing test 2. I missed the first one but I tried it right now and it consistently passes. The timeout is rather because the release we are testing is not booting, we would need to find the root cause why or provide a way to consistently reproduce it. :(

[cjschneider2]

I have the same problem for the first mentioned failing test; in the log in which it's waiting for a message there is only the following:

=====
===== LOGGING STARTED Wed Jun 21 22:37:28 CEST 2023
=====
No file named :elixir.start_iex()

This build was a fresh pull from master. I'll try to figure out why it can't find it but @josevalim will probably be faster than I ;)

[josevalim]

This is where the flag is used: https://github.com/elixir-lang/elixir/blob/main/bin/iex#L33

but I can’t see how it would be handled as a file. Can you folks boot IEx as usual? Do you have any env vars that configure Erlang or Elixir which could affect this behavior? Perhaps you are using a different shell?

[cjschneider2]

Hmm I have a relatively vanilla Arch install, no specific EnvVars for Elixir/Erlang running bash:

$ elixir --version
Erlang/OTP 26 [erts-14.0.1] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit:ns]

Elixir 1.14.5 (compiled with Erlang/OTP 26)

Experimenting with the release script from the test, the following options work:

• start
• start_iex
• daemon
  The one having problems (which is the one used in the test) is daemon_iex which errors with the message: No file named :elixir.start_iex() like before

[nallwhy]

Hmm I have a relatively vanilla Arch install, no specific EnvVars for Elixir/Erlang running bash:

$ elixir --version
Erlang/OTP 26 [erts-14.0.1] [source] [64-bit] [smp:8:8] [ds:8:8:10] [async-threads:1] [jit:ns]

Elixir 1.14.5 (compiled with Erlang/OTP 26)

Experimenting with the release script from the test, the following options work:

• start
• start_iex
• daemon
  The one having problems (which is the one used in the test) is daemon_iex which errors with the message: No file named :elixir.start_iex() like before

I have the same issue. daemon_iex not work.
But I don't know the reason to use daemon_iex over daemon.

[cjschneider2]

@josevalim (I see you've changed some of this code, but maybe it'll also help with that problem?)

It seems that we're running into a problem with the startup script for elixir in a release.

The first part is that in the iex startup script iex is was started by adding the option: -e ":elixir.start_iex()" to the command list. Sometime later in the elixir boot script the options are escaped by using the function here:

elixir/bin/elixir

Line 236 in 7303e58

ESCAPED="$ESCAPED $(echo "$PART" | sed 's@[^a-zA-Z0-9_/-]@\\&@g')"

In some shells however it seems that echo "-e" triggers an option in echo to interpret escaped characters and returns an empty string (as there is no other input) effectively deleting the -e option and leaving us with ":elixir.start_iex()". This is interpreted as a file in parse_args() as a fall-through. This is where the No file named :elixir.start_iex() comes from.

A general fix for this would be to have the filter function use printf '%s' "$PART" instead of echo "$PART" and/or using the full command option --eval in the iex script.

[josevalim]

@cjschneider2 great find. A PR for using printf would be great. Would you like to submit one?

[cjschneider2]

Yea, I'll prepare one :)

[josevalim]

Closing in favor of the PR.