Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Pass async to tests, parallelizing them #405

Merged
merged 5 commits into from
Nov 10, 2024
Merged

Pass async to tests, parallelizing them #405

merged 5 commits into from
Nov 10, 2024

Conversation

PragTob
Copy link
Collaborator

@PragTob PragTob commented Oct 4, 2024

Tests run sync by default. But all of Elixir, essentially, is built to run tests in parallel/async. Unless you mess with the global environment there's usually no reason not to run tests in parallel and it's also best practice to always pass either async: true or async: false and a reason why they can't be run in parallel.

Speeds up the test suite, admittedly not by a lot right now but it's nice.

Also enables a lint for these.

I didn't check all the tests for global state, so this may introduce flakies but on a first couple of runs everything seemed fine.

async:

root@812d17669fe3:/app# mix test
*********....................................................................................................................................................
Finished in 0.7 seconds (0.7s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 325387
root@812d17669fe3:/app# mix test
***.******...................................................................................................................................................
Finished in 0.6 seconds (0.6s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 874856
root@812d17669fe3:/app# mix test
*********....................................................................................................................................................
Finished in 0.7 seconds (0.7s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 194987
root@812d17669fe3:/app# mix test
*********....................................................................................................................................................
Finished in 0.6 seconds (0.6s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 426291
root@812d17669fe3:/app# mix test
***..******..................................................................................................................................................
Finished in 0.7 seconds (0.7s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

sync:

root@812d17669fe3:/app# mix test
Compiling 3 files (.ex)
......................................................................................******............08:54:11.449 [error] Postgrex.Protocol (#PID<0.394.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2162.0> exited
...............***...................................
Finished in 1.6 seconds (0.00s async, 1.6s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 38709
root@812d17669fe3:/app# mix test
.................................................................................******.........................08:54:18.537 [error] Postgrex.Protocol (#PID<0.373.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2293.0> exited
.............***.............................
Finished in 1.8 seconds (0.00s async, 1.8s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 848590
root@812d17669fe3:/app# mix test
......................................................................................******...........08:54:22.337 [error] Postgrex.Protocol (#PID<0.374.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2118.0> exited
..............***.....................................
Finished in 1.8 seconds (0.00s async, 1.8s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 729972
root@812d17669fe3:/app# mix test
......................................................................................******........................08:54:26.003 [error] Postgrex.Protocol (#PID<0.375.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2282.0> exited
.......***...............................
Finished in 1.9 seconds (0.00s async, 1.9s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 249736
root@812d17669fe3:/app# mix test
..........................................................................******..............................08:54:29.869 [error] Postgrex.Protocol (#PID<0.370.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2196.0> exited
.........***...................................
Finished in 1.8 seconds (0.00s async, 1.8s sync)
157 tests, 0 failures, 9 skipped

Magically it also seems to have gotten rid off that one error, but really don't ask me why.

Further Notes

  • Additional context information

New Features / Enhancements

  • Adding screenshot or other media to brag about the new feature ;-)

After Merge Checklist

  • Item 1

@PragTob PragTob force-pushed the async-tests branch 2 times, most recently from 11ee3bd to 707559e Compare October 5, 2024 07:33
@PragTob
Copy link
Collaborator Author

PragTob commented Oct 7, 2024

Ah nice it caught a test that's not fully async safe:

   1) test delete_inactive_users does not delete the user a user is a moderating user of a brainstorming (Mindwendel.AccountsTest)
     test/mindwendel/accounts_test.exs:119
     Assertion with == failed
     code:  assert log == ""
Error: ft:  "13:52:33.791 [error] An error occured when executing the migration script.\nPlease ensure the table idea_idea_labels is created and empty before executing this migration\nscript.\n\n13:52:33.793 [error] ** (Postgrex.Error) ERROR 23505 (unique_violation) duplicate key value violates unique constraint \"idea_idea_labels_pkey\"\n\n    table: idea_idea_labels\n    constraint: idea_idea_labels_pkey\n\nKey (idea_id, idea_label_id)=(08fe0da4-6307-4522-8928-860740bb40f8, df22a09c-280f-414d-b98c-fae3afd67651) already exists.\n    (ecto_sql 3.12.0) lib/ecto/adapters/sql.ex:1078: Ecto.Adapters.SQL.raise_sql_call_error/1\n    priv/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels.exs:6: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabels.run/0\n    (ex_unit 1.15.8) lib/ex_unit/assertions.ex:785: ExUnit.Assertions.assert_raise/2\n    test/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels_test.exs:68: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabelsTest.\"test fails gracefully\"/1\n    (ex_unit 1.15.8) lib/ex_unit/runner.ex:463: ExUnit.Runner.exec_test/2\n    (ex_unit 1.15.8) lib/ex_unit/capture_log.ex:113: ExUnit.CaptureLog.with_log/2\n    (ex_unit 1.15.8) lib/ex_unit/runner.ex:412: anonymous fn/3 in ExUnit.Runner.maybe_capture_log/3\n    (stdlib 5.2.3) timer.erl:270: :timer.tc/2\n    (ex_unit 1.15.8) lib/ex_unit/runner.ex:385: anonymous fn/5 in ExUnit.Runner.spawn_test_monitor/4\n\n"
     right: ""
     stacktrace:
       test/mindwendel/accounts_test.exs:134: (test)

     The following output was logged:
Error:      13:52:33.791 [error] An error occured when executing the migration script.
     Please ensure the table idea_idea_labels is created and empty before executing this migration
     script.
     
Error:      13:52:33.793 [error] ** (Postgrex.Error) ERROR 23505 (unique_violation) duplicate key value violates unique constraint "idea_idea_labels_pkey"
     
         table: idea_idea_labels
         constraint: idea_idea_labels_pkey
     
     Key (idea_id, idea_label_id)=(08fe0da4-6307-4522-8928-860740bb40f8, df22a09c-280f-414d-b98c-fae3afd67651) already exists.
         (ecto_sql 3.12.0) lib/ecto/adapters/sql.ex:1078: Ecto.Adapters.SQL.raise_sql_call_error/1
         priv/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels.exs:6: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabels.run/0
         (ex_unit 1.15.8) lib/ex_unit/assertions.ex:785: ExUnit.Assertions.assert_raise/2
         test/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels_test.exs:68: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabelsTest."test fails gracefully"/1
         (ex_unit 1.15.8) lib/ex_unit/runner.ex:463: ExUnit.Runner.exec_test/2
         (ex_unit 1.15.8) lib/ex_unit/capture_log.ex:113: ExUnit.CaptureLog.with_log/2
         (ex_unit 1.15.8) lib/ex_unit/runner.ex:412: anonymous fn/3 in ExUnit.Runner.maybe_capture_log/3
         (stdlib 5.2.3) timer.erl:270: :timer.tc/2
         (ex_unit 1.15.8) lib/ex_unit/runner.ex:385: anonymous fn/5 in ExUnit.Runner.spawn_test_monitor/4

log capturing may capture logs from other processes.

Fix is either:

  • make the check more specific so that in this case it checks that a specific log message isn't emitted (at best using an ID or something)
  • making the test sync again

Tests run sync by default. But all of Elixir, essentially, is
built to run tests in parallel/async. Unless you mess with the
global environment there's usually no reason not to run tests
in parallel and it's also best practice to always pass
either `async: true` or `async: false` and a reason why they
can't be run in parallel.

Speeds up the test suite, admittedly not by a lot right now but
it's nice.

I didn't check all the tests for global state, so this may
introduce flakies but on a first couple of runs everything seemed fine.

async:

```
root@812d17669fe3:/app# mix test
*********....................................................................................................................................................
Finished in 0.7 seconds (0.7s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 325387
root@812d17669fe3:/app# mix test
***.******...................................................................................................................................................
Finished in 0.6 seconds (0.6s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 874856
root@812d17669fe3:/app# mix test
*********....................................................................................................................................................
Finished in 0.7 seconds (0.7s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 194987
root@812d17669fe3:/app# mix test
*********....................................................................................................................................................
Finished in 0.6 seconds (0.6s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 426291
root@812d17669fe3:/app# mix test
***..******..................................................................................................................................................
Finished in 0.7 seconds (0.7s async, 0.00s sync)
157 tests, 0 failures, 9 skipped

```

sync:

```
root@812d17669fe3:/app# mix test
Compiling 3 files (.ex)
......................................................................................******............08:54:11.449 [error] Postgrex.Protocol (#PID<0.394.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2162.0> exited
...............***...................................
Finished in 1.6 seconds (0.00s async, 1.6s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 38709
root@812d17669fe3:/app# mix test
.................................................................................******.........................08:54:18.537 [error] Postgrex.Protocol (#PID<0.373.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2293.0> exited
.............***.............................
Finished in 1.8 seconds (0.00s async, 1.8s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 848590
root@812d17669fe3:/app# mix test
......................................................................................******...........08:54:22.337 [error] Postgrex.Protocol (#PID<0.374.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2118.0> exited
..............***.....................................
Finished in 1.8 seconds (0.00s async, 1.8s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 729972
root@812d17669fe3:/app# mix test
......................................................................................******........................08:54:26.003 [error] Postgrex.Protocol (#PID<0.375.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2282.0> exited
.......***...............................
Finished in 1.9 seconds (0.00s async, 1.9s sync)
157 tests, 0 failures, 9 skipped

Randomized with seed 249736
root@812d17669fe3:/app# mix test
..........................................................................******..............................08:54:29.869 [error] Postgrex.Protocol (#PID<0.370.0>) disconnected: ** (DBConnection.ConnectionError) owner #PID<0.2196.0> exited
.........***...................................
Finished in 1.8 seconds (0.00s async, 1.8s sync)
157 tests, 0 failures, 9 skipped

```

Magically it also seems to have gotten rid off that one error, but really don't ask me why.
@JannikStreek JannikStreek merged commit 5213ae2 into master Nov 10, 2024
8 checks passed
@JannikStreek JannikStreek deleted the async-tests branch November 10, 2024 20:01
@JannikStreek
Copy link
Member

@PragTob locally, just got this. Maybe you can have a look at it. Its a random fail, does not happen every time:

  1) test delete_inactive_users does not delete the user is still attached to ideas (Mindwendel.AccountsTest)
     test/mindwendel/accounts_test.exs:85
     Assertion with == failed
     code:  assert log == ""
     left:  "\e[31m08:10:35.156 [error] An error occured when executing the migration script.\nPlease ensure the table idea_idea_labels is created and empty before executing this migration\nscript.\n\n\e[0m\e[31m08:10:35.157 [error] ** (Postgrex.Error) ERROR 23505 (unique_violation) duplicate key value violates unique constraint \"idea_idea_labels_pkey\"\n\n    table: idea_idea_labels\n    constraint: idea_idea_labels_pkey\n\nKey (idea_id, idea_label_id)=(d45edb55-81dd-4f5b-81ae-081ff66647d8, 1511e826-ac47-4f58-afa5-df9be954eacd) already exists.\n    (ecto_sql 3.12.1) lib/ecto/adapters/sql.ex:1096: Ecto.Adapters.SQL.raise_sql_call_error/1\n    priv/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels.exs:6: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabels.run/0\n    (ex_unit 1.15.8) lib/ex_unit/assertions.ex:785: ExUnit.Assertions.assert_raise/2\n    test/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels_test.exs:68: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabelsTest.\"test fails gracefully\"/1\n    (ex_unit 1.15.8) lib/ex_unit/runner.ex:463: ExUnit.Runner.exec_test/2\n    (ex_unit 1.15.8) lib/ex_unit/capture_log.ex:113: ExUnit.CaptureLog.with_log/2\n    (ex_unit 1.15.8) lib/ex_unit/runner.ex:412: anonymous fn/3 in ExUnit.Runner.maybe_capture_log/3\n    (stdlib 5.2.3) timer.erl:270: :timer.tc/2\n    (ex_unit 1.15.8) lib/ex_unit/runner.ex:385: anonymous fn/5 in ExUnit.Runner.spawn_test_monitor/4\n\n\e[0m"
     right: ""
     stacktrace:
       test/mindwendel/accounts_test.exs:98: (test)

     The following output was logged:
     08:10:35.156 [error] An error occured when executing the migration script.
     Please ensure the table idea_idea_labels is created and empty before executing this migration
     script.
     
     08:10:35.157 [error] ** (Postgrex.Error) ERROR 23505 (unique_violation) duplicate key value violates unique constraint "idea_idea_labels_pkey"
     
         table: idea_idea_labels
         constraint: idea_idea_labels_pkey
     
     Key (idea_id, idea_label_id)=(d45edb55-81dd-4f5b-81ae-081ff66647d8, 1511e826-ac47-4f58-afa5-df9be954eacd) already exists.
         (ecto_sql 3.12.1) lib/ecto/adapters/sql.ex:1096: Ecto.Adapters.SQL.raise_sql_call_error/1
         priv/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels.exs:6: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabels.run/0
         (ex_unit 1.15.8) lib/ex_unit/assertions.ex:785: ExUnit.Assertions.assert_raise/2
         test/repo/data_migrations/migrate_idea_labels_to_idea_idea_labels_test.exs:68: Mindwendel.Repo.DataMigrations.MigrateIdeaLabelsToIdeaIdeaLabelsTest."test fails gracefully"/1
         (ex_unit 1.15.8) lib/ex_unit/runner.ex:463: ExUnit.Runner.exec_test/2
         (ex_unit 1.15.8) lib/ex_unit/capture_log.ex:113: ExUnit.CaptureLog.with_log/2
         (ex_unit 1.15.8) lib/ex_unit/runner.ex:412: anonymous fn/3 in ExUnit.Runner.maybe_capture_log/3
         (stdlib 5.2.3) timer.erl:270: :timer.tc/2
         (ex_unit 1.15.8) lib/ex_unit/runner.ex:385: anonymous fn/5 in ExUnit.Runner.spawn_test_monitor/4

@PragTob
Copy link
Collaborator Author

PragTob commented Nov 11, 2024

@JannikStreek yup that's a classic, you can't run tests in parallel and assert logs with == a simple regex match should fix that (or relying on other data)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants