Fix flaky logger test

[solnic]

This just adds a couple of timeouts for assert_receive to reduce the risk of random test failures.

Closes #896

#skip-changelog

[solnic]

@whatyouhide I ran it a bunch of times with --repeat-until-failure 100 and it pointed to another one so I added a timeout there too. Unfortunately running all tests from this file with this option yields random failures too, same with running the whole suite. These were harder to figure out so I'm gonna just report them separately whenever (and if) I see them when running regular CI builds.

[whatyouhide]

These were harder to figure out

What do you mean? Can we catalogue them? Also, did you use --repeat-until-failure in CI or locally? CI tends to be significantly slower.

[solnic]

These were harder to figure out

What do you mean? Can we catalogue them? Also, did you use --repeat-until-failure in CI or locally? CI tends to be significantly slower.

This is outside of the scope of this PR. I just want to get that merged as it addresses a couple of flaky tests.

Other two failures I see when I run tests with --repeat-until-failure 100 option are:

  1) test send_event/2 dedupes events (Sentry.ClientTest)
     test/sentry/client_test.exs:407
     match (=) failed
     code:  assert {:ok, "340"} = Client.send_event(event, [])
     left:  {:ok, "340"}
     right: :excluded
     stacktrace:
       test/sentry/client_test.exs:432: anonymous fn/3 in Sentry.ClientTest."test send_event/2 dedupes events"/1
       (elixir 1.18.4) lib/enum.ex:2546: Enum."-reduce/3-lists^foldl/2-0-"/3
       test/sentry/client_test.exs:427: (test)

and

  1) test discard threshold discards logged messages (Sentry.LoggerHandlerTest)
     test/sentry/logger_handler_test.exs:650
     Assertion failed, no matching message after 5000ms
     The following variables were pinned:
       ref = #Reference<0.2667273741.3767795718.57688>
     The process mailbox is empty.
     code: assert_receive {^ref, %{message: %{formatted: "Second"}}}
     stacktrace:
       test/sentry/logger_handler_test.exs:657: (test)

     The following output was logged:
     
     12:56:42.568 [error] First
     
     12:56:42.569 [error] Second
     
     12:56:42.569 [error] Third

Both locally and on CI. It seems like it's specific to the repeat option though. I don't recall seeing these failures in normal CI builds.

[martosaur]

sorry for an uninvited comment folks, but I just wanted to highlight a project I released some time ago LoggerHandlerKit. It's made specifically to facilitate logger handler tests and share test cases between projects. When I first released it I applied it to Sentry's test suite on a branch, so if you're down, I can revisit it and make a proper PR. It's currently used in DiscoLog and LogHog.

[whatyouhide]

@martosaur that's interesting, thanks for the link! I personally don't think we should add another dependency to Sentry considering this is functionally working.