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

Possibly flakey test #41

Open
jamtur01 opened this issue Jun 25, 2022 · 3 comments
Open

Possibly flakey test #41

jamtur01 opened this issue Jun 25, 2022 · 3 comments

Comments

@jamtur01
Copy link
Member

https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true

[69](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:70)
  - should raise Riemann::Client::Unsupported exception on query
[70](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:71)
[71](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:72)
RuntimeError: wait_for condition never realized
[72](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:73)
	spec/client.rb:35:in `wait_for': Riemann::Client (UDP transport) - should send a state without time nor time_micros
[73](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:74)
	spec/client.rb:155:in `block (2 levels) in <top (required)>'
[74](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:75)
	spec/client.rb:149:in `block in <top (required)>'
[75](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:76)
	spec/client.rb:334:in `block in <top (required)>'
[76](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:77)
	spec/client.rb:328:in `<top (required)>'
[77](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:78)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/cli/exec.rb:58:in `load'
[78](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:79)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/cli/exec.rb:58:in `kernel_load'
[79](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:80)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/cli/exec.rb:23:in `run'
[80](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:81)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/cli.rb:479:in `exec'
[81](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:82)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
[82](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:83)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
[83](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:84)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
[84](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:85)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/cli.rb:31:in `dispatch'
[85](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:86)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
[86](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:87)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/cli.rb:25:in `start'
[87](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:88)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/exe/bundle:48:in `block in <top (required)>'
[88](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:89)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/lib/bundler/friendly_errors.rb:117:in `with_friendly_errors'
[89](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:90)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/lib/ruby/gems/3.1.0/gems/bundler-2.3.16/exe/bundle:36:in `<top (required)>'
[90](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:91)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/bin/bundle:25:in `load'
[91](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:92)
	/opt/hostedtoolcache/Ruby/3.1.2/x64/bin/bundle:25:in `<main>'
[92](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:93)
[93](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:94)
49 specifications (107 requirements), 0 failures, 1 errors
[94](https://github.com/riemann/riemann-ruby-client/runs/7054304294?check_suite_focus=true#step:5:95)
Error: Process completed with exit code 1.
@smortex
Copy link
Member

smortex commented Jun 25, 2022

I can reproduce the issue.

By keeping a track of the time before we send the event and the time_micros of the event we found, there seems to be some rounding: all time_micros for the events I see ends with 000.

Real world example, the time recorded at the beginning of the test is 1656185604104042. Then the event is sent.

First found event has 1656185602001000, it is the one from the previous test because the one we just sent is not in the index yet:

[#<Riemann::Event time=1656185602 state="ok" service="timeless test" host="zappy.blogreen.org" description="" tags=[] ttl=60.0 attributes=[] time_micros=1656185602001000 metric_sint64=0 metric_d=0.0 metric_f=0.0>]

Next found event is the expected one, but the time_micros field is 1656185604104000 and appears to be older that the timestamp at the beginning of the test: 1656185604104042

[#<Riemann::Event time=1656185604 state="ok" service="timeless test" host="zappy.blogreen.org" description="" tags=[] ttl=60.0 attributes=[] time_micros=1656185604104000 metric_sint64=0 metric_d=0.0 metric_f=0.0>]

Reverting 5ab5de4 events have "better" resolution:

  - should send a state without time nor time_micros
---> 1656186828800656
[<Riemann::Event time: 1656186826, state: "ok", service: "timeless test", host: "zappy.blogreen.org", ttl: 60.0, time_micros: 1656186826388166>]
[<Riemann::Event time: 1656186828, state: "ok", service: "timeless test", host: "zappy.blogreen.org", ttl: 60.0, time_micros: 1656186828800753>]

So the root issue seems to be in the protobuf gem.

@jamtur01
Copy link
Member Author

@smortex Happy to have you revert the gem change? Or investigate with them upstream?

smortex added a commit that referenced this issue Jun 25, 2022
This reverts commit 5ab5de4.

See discussion in #41
@smortex
Copy link
Member

smortex commented Jun 25, 2022

Let's do this for now while we investigate. I am still searching where the magic of setting time_micros happen: can't find it in riemann, nor the protocol buffers gems…

The same issue is triggered with the google-protobuf gem (I have some WIP here, but it is only partially functional ATM, I was thinking that using the implementation from google may be a better choice for the long term, also it has less dependencies, is written in C and triggers less errors when running the tests with RSpec 😄).

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

No branches or pull requests

2 participants