Skip to content

Commit

Permalink
realtime_block: log timings to stderr on exception in outermost block
Browse files Browse the repository at this point in the history
Not necessary in inner blocks as timing still gets stored in hash
and if caught will be returned from some outer block.
When outermost block crashes, the whole hash is about to be discarded.
  • Loading branch information
cben committed Sep 27, 2017
1 parent a299923 commit 0fc0ab1
Show file tree
Hide file tree
Showing 2 changed files with 41 additions and 0 deletions.
4 changes: 4 additions & 0 deletions lib/gems/pending/util/extensions/miq-benchmark.rb
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,10 @@ def self.realtime_block(key, &block)
begin
ret = realtime_store(hash, key, &block)
return ret, hash
rescue Exception
# Don't let timings be lost on exception when there is nobody else to pick them up.
Logger.new($stderr).info("Exception in realtime_block #{key.inspect} - Timings: #{hash.inspect}")
raise
ensure
delete_current_realtime
end
Expand Down
37 changes: 37 additions & 0 deletions spec/util/extensions/miq-benchmark_spec.rb
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,43 @@
expect(Benchmark.in_realtime_block?).to be_falsey
end

it '.realtime_block with an Exception aborting outermost block' do
expect do
Benchmark.realtime_block(:test1) do
Timecop.travel(2.1)
Benchmark.realtime_block(:test2) do
Timecop.travel(5.1)
raise Exception
end
end
end.to raise_exception(Exception)
.and output(/Exception in realtime_block :test1 - Timings: {:test2=>5\.\d*, :test1=>7\.\d*}/).to_stderr

expect(Benchmark.in_realtime_block?).to be_falsey
end

it '.realtime_block with an Exception caught in inner block' do
result = timings = nil
expect do
result, timings = Benchmark.realtime_block(:test1) do
begin
Timecop.travel(500)
Benchmark.realtime_block(:test2) do
Timecop.travel(500)
raise Exception
end
rescue Exception
"value"
end
end
end.to_not output.to_stderr

expect(result).to eq("value")
expect(timings[:test1]).to be_within(0.5).of(1000)
expect(timings[:test2]).to be_within(0.5).of(500)
expect(Benchmark.in_realtime_block?).to be_falsey
end

it "Timeout raising within .realtime_block" do
expect(Benchmark.in_realtime_block?).to be_falsey

Expand Down

0 comments on commit 0fc0ab1

Please sign in to comment.