ExUnit: end-of-run test counts wrong when I run mix test in an umbrella app.

[myronmarston]

Environment

• Elixir version (elixir -v):

Erlang/OTP 18 [erts-7.3] [source] [64-bit] [smp:4:4] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Elixir 1.3.2

• Operating system:

OS X El Capitan

Current behavior

I've occasionally noticed that mix test in my umbrella app produces results that greatly exaggerate the number of tests in some of the sub-apps. Here's the complete output from running mix test. Notice the results for several of these apps:

==> s3
Excluding tags: [:manual, :smoke]

...

Finished in 0.5 seconds
103 tests, 0 failures

Randomized with seed 335614

3 dots -- but it said it ran 103 tests.

==> crawl_fetcher
Excluding tags: [:manual, :smoke]

........

Finished in 0.1 seconds
108 tests, 0 failures

Randomized with seed 335614

8 dots -- but it said it ran 108 tests.

In general, virtually all of the test counts seem to have an extra 100 for some reason. Note that when I cd into the directory for one of these apps, it reports the total correctly:

➜  s3 git:(master) mix test
Excluding tags: [:manual]

...

Finished in 0.7 seconds
3 tests, 0 failures

Randomized with seed 551253

Likewise, for rankings_endpoint_models, which was reported as having 606 tests from the umbrella root, it reports 506 tests when run directly from its directory.

Digging in a little bit, it looks like all the apps listed before common_models reported their counts correctly, then common_models reported 286 when the real number is 186, and every app run after that has its total inflated by 100. It's like the test count gets reset to 100 instead of 0 once one app has more than 100 tests (but I suspect the actual above is more nuanced than that...)

Expected behavior

I expect ExUnit to correctly report the number of tests it ran :).

[ipinak]

Try to run it with --trace to get a more detailed output of what was executed. Maybe that can help with troubleshooting.

http://elixir-lang.org/docs/stable/mix/Mix.Tasks.Test.html#module-command-line-options

[myronmarston]

I'm not sure how the --trace output will help, given that it just gives you the test descriptions that are specific to our application's domain...but here's one part of it (for the s3 app mentioned above):

==> s3
Excluding tags: [:manual, :smoke]


Delorean.S3Test

Delorean.S3AcceptanceTest
  * test both clients calculate `presigned_get_url` in the same way (and the URL works) (195.1ms)
  * test `Delorean.S3.Test.FakeS3` can upload objects to S3 and later list and fetch them (13.2ms)
  * test `Delorean.S3` can upload objects to S3 and later list and fetch them (330.6ms)


Finished in 0.7 seconds
103 tests, 0 failures

Randomized with seed 54640

It printed 3 tests, but then reported the total number of tests as 103.

[josevalim]

@myronmarston maybe they are really good tests and Elixir is just giving you bonus points. 😅

[wojtekmach]

@myronmarston it's a long shot, but do you have any skipped tests? I noticed this: Excluding tags: [:manual, :smoke]. Perhaps, for some reason, we don't show the skipped tests in the summary.

[ipinak]

@myronmarston the formatter that handles this output seems to work correctly, it's weird that it consistently or kind of consistently adds 100. More specifically it counts every test, even the skipped ones. So it might be that the :manual and :smoke tests are 100. Just a guess.

[myronmarston]

Yes, we have some skipped tests, but we definitely do not have 100 and that's not what's going on here. When there are skipped tests, ExUnit includes the number in the summary. For example, here's the output for one of our other sub-apps:

==> pager_duty
Excluding tags: [:manual, :smoke]


Delorean.PagerDutyIntegrationTest
  * test trigger PagerDuty incident (skipped)

Delorean.PagerDutyTest
  * test `trigger` passes url (0.1ms)
  * test `trigger` injects service_key, event_type, and description into body (0.1ms)
  * test `trigger` passes its name (0.1ms)
  * test `trigger` returns post result (tuple with status_code and parsed body) (0.1ms)
  * test `trigger` ignores invalid params (0.1ms)
  * test `trigger` uses passed valid params in the formed body (0.1ms)


Finished in 0.1 seconds
107 tests, 0 failures, 1 skipped

Randomized with seed 54640

Notice that there are 7 tests total, of which 1 was skipped. The summary line says "107 tests, 0 failures, 1 skipped". For the s3 sub-app I pasted the output for above, it has no skipped tests.

Overall, my test suite has 11 tests that are skipped by excluding :manual and :smoke. There does not seem to be a correlation to the 100-test inflation in the total.

[josevalim]

I have tried to reproduce the issue but unfortunately I could not. More information or a mechanism that reproduces it is appreciated.

[michalmuskala]

Do you use some libraries that inject themselves into ex_unit? I know some property checking libraries used to mess up the test count.

[myronmarston]

Do you use some libraries that inject themselves into ex_unit? I know some property checking libraries used to mess up the test count.

Thanks for the suggestion--this is definitely the problem. Our suite uses ExCheck and it is definitely causing the issue -- I commented out our use of it and the counts are reporting correctly now. Wish I could have realized it was at fault sooner :(.

Thanks for looking into this and helping me figure it out!