Skip to content
This repository has been archived by the owner on Oct 12, 2022. It is now read-only.

Test suite sporadically fails with test_asynchronous_queue.rb:44 #53

Closed
mattrayner opened this issue Apr 26, 2018 · 1 comment
Closed

Comments

@mattrayner
Copy link
Contributor

Whilst working on #48 I've noticed that you have a sporadic test failure (appears roughly one in 10 times for me)

Stack trace

================================================================================================================================================
Error: test_flush_works_as_expected(TestAsynchronousQueue)
:
  fatal: No live threads left. Deadlock?
  1 threads, 1 sleeps current:0x00007ff7cd7b8930 main thread:0x00007ff7cbc0c4b0
  * #<Thread:0x00007ff7cc081c60 sleep_forever>
     rb_thread_t:0x00007ff7cbc0c4b0 native:0x00007fff928ab380 int:1
     /Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:61:in `sleep'
     /Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:61:in `wait'
     /Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:61:in `block in wait'
     /Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:60:in `synchronize'
     /Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:60:in `wait'
     /Users/mattrayner/projects/ApplicationInsights-Ruby/test/application_insights/channel/test_asynchronous_queue.rb:44:in `test_flush_works_as_expected'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/testcase.rb:697:in `run_test'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/testcase.rb:437:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/testsuite.rb:121:in `run_test'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/testsuite.rb:53:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/testsuite.rb:121:in `run_test'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/testsuite.rb:53:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunnermediator.rb:65:in `run_suite'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunnermediator.rb:44:in `block in run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunnermediator.rb:100:in `with_listener'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunnermediator.rb:40:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunner.rb:40:in `start_mediator'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunner.rb:25:in `start'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/ui/testrunnerutilities.rb:24:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/autorunner.rb:403:in `block in run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/autorunner.rb:459:in `change_work_directory'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/autorunner.rb:402:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit/autorunner.rb:59:in `run'
     /Users/mattrayner/.rvm/gems/ruby-2.5.1/gems/test-unit-3.0.9/lib/test/unit.rb:502:in `block (2 levels) in <top (required)>'
/Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:61:in `sleep'
/Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:61:in `wait'
/Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:61:in `block in wait'
/Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:60:in `synchronize'
/Users/mattrayner/projects/ApplicationInsights-Ruby/lib/application_insights/channel/event.rb:60:in `wait'
/Users/mattrayner/projects/ApplicationInsights-Ruby/test/application_insights/channel/test_asynchronous_queue.rb:44:in `test_flush_works_as_expected'
     41:     assert_equal false, result
     42:     queue.flush
     43:     assert_equal 1, sender.start_call_count
  => 44:     result = queue.flush_notification.wait
     45:     assert_equal true, result
     46:   end
     47: end
================================================================================================================================================

I'm going to have a go at investigating, but wanted to raise it early

@yantang-msft
Copy link
Contributor

I experienced the same issue, this assertion is fairly unreliable.
To be more concrete, once the sender thread reaches to this line https://github.com/Microsoft/ApplicationInsights-Ruby/blob/develop/lib/application_insights/channel/asynchronous_sender.rb#L104
before the assertion, the notification will be clear, thus result = queue.flush_notification.wait will return false.
I've fixed this in #57, which simply drops this assertion. The main purpose of this test case is to make sure when flush is called, the sender will start().

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

No branches or pull requests

2 participants