Skip to content

correct/revisit exception backtrace (and stack-trace)#6014

Merged
kares merged 10 commits intojruby:masterfrom
kares:fix-exception-backtrace
Jan 8, 2020
Merged

correct/revisit exception backtrace (and stack-trace)#6014
kares merged 10 commits intojruby:masterfrom
kares:fix-exception-backtrace

Conversation

@kares
Copy link
Member

@kares kares commented Dec 31, 2019

original motivation for these changes was that the internal "lightweight" forced backtrace didn't have any reduced impact over a normal raise but also the fast that the legacy Java parts got neglected (not having the proper forced stack-trace as before).

last part is probably due having two TestRaiseException cases - one of which wasn't run since the recent changes (adding the Java exception hierarchy for Ruby ones) ...

than I realized RaiseException usually replaces a custom Java trace so not need to initially fillInStackTrace (which turned out to be potentially incorrectly on with -Xjump.backtrace)

p.s. also added some minor pre-filtering (e.g. getStackTrace from top - has been bothering me for a while 🙈) - we could take it further to skip the Java stack trace head to not include all of the exception <init> (all the way to java.lang.Throwable.<init>) ... maybe later.

kares added 9 commits December 30, 2019 13:03
@kares
[fix] raise with backtrace to only 'pre' once
4c03d3f 
previously the constructor would hit preRaise twice
forcefully generating an unnecessary backtrace ...
@kares
[fix] do not capture when nil backtrace given
8f98638
@kares
[test] RaiseException.from working + fix old asserts
42a9e31
@kares
[refactor] cleanup - make sure we use a common preRaise
15ef947
@kares
[refactor] minor - array-list size might be known
ed72b69
@kares
[fix] proper exception backtrace (capture)
4968e77 
- from the Ruby side we did not check set exception.backtrace
  handle case when its set (backtrace disabled) properly
- the legacy Java side always had its own stack-trace
  (regardless of the requested java trace parameter)

also added some preliminary filtering to skip internal parts
... there's certainly room to skip more in certain cases
@kares
[test] merge TestRaiseException cases and run on main suite
aa2f149
@kares
[perf] disable initial stack-trace filling
35e1f29 
since we always setStackTrace manually (from ctor)
@kares
[feat] some (fast) filtering to reduce Java trace
92dc9a3
@kares kares added this to the JRuby 9.2.10.0 milestone Dec 31, 2019
@kares
Copy link
Member Author

kares commented Dec 31, 2019

numbers confirm that a forced back-trace now is much faster (raise RuntimeError, '', nil) :

Warming up --------------------------------------
       raise default   841.000  i/100ms
 raise nil backtrace   898.000  i/100ms
Calculating -------------------------------------
       raise default      9.296k (± 1.2%) i/s -     93.351k in  10.044026s
 raise nil backtrace      9.290k (± 1.8%) i/s -     93.392k in  10.056207s

Warming up --------------------------------------
       raise default   867.000  i/100ms
 raise nil backtrace    78.471k i/100ms
Calculating -------------------------------------
       raise default      9.434k (± 1.6%) i/s -     94.503k in  10.019629s
 raise nil backtrace      1.626M (± 2.2%) i/s -     16.322M in  10.040849s

@kares
Copy link
Member Author

kares commented Dec 31, 2019

Java 11 is half the speed for 'normal' raises (no change and I re-call this is a known thing) :

jruby 9.2.9.0 (2.5.7) 2019-10-30 458ad3e Java HotSpot(TM) 64-Bit Server VM 11.0.2+9-LTS on 11.0.2+9-LTS +jit [linux-x86_64]

Warming up --------------------------------------
       raise default   449.000  i/100ms
 raise nil backtrace   466.000  i/100ms
Calculating -------------------------------------
       raise default      4.695k (± 1.7%) i/s -     47.145k in  10.045269s
 raise nil backtrace      4.665k (± 1.8%) i/s -     47.066k in  10.092519s

jruby 9.2.10.0-SNAPSHOT (2.5.7) 2019-12-31 fe4b188 Java HotSpot(TM) 64-Bit Server VM 11.0.2+9-LTS on 11.0.2+9-LTS +jit [linux-x86_64]

Warming up --------------------------------------
       raise default   464.000  i/100ms
 raise nil backtrace    72.106k i/100ms
Calculating -------------------------------------
       raise default      4.962k (± 1.1%) i/s -     49.648k in  10.006191s
 raise nil backtrace      1.489M (± 1.2%) i/s -     14.926M in  10.027093s

... maybe something to tackle with later 🤞

@kares kares changed the title Fix exception backtrace [fix] proper exception backtrace (and Java stack-trace) Dec 31, 2019
@kares kares changed the title [fix] proper exception backtrace (and Java stack-trace) correct/revisit exception backtrace (and stack-trace) Dec 31, 2019
headius
headius reviewed Jan 7, 2020
View reviewed changes
Copy link
Member

@headius headius left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good to me, with a couple comments on filtering that we should maybe discuss outside this PR. I assume this broke when we (probably me) reworked raise workflow to match CRuby more exactly? I know I ran benchmarks that showed force backtrace was much faster not too long ago. Very nice to have some tests that ensure we're not generating multiple traces.

@headius
Copy link
Member

headius commented Jan 7, 2020

That's a 👍 from me even though I submitted the review as a general comment.

@kares kares merged commit a961fb3 into jruby:master Jan 8, 2020
@kares kares mentioned this pull request Jan 12, 2020
Merged
@highb highb mentioned this pull request Mar 17, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@headius headius headius left review comments

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

JRuby 9.2.10.0

Development

Successfully merging this pull request may close these issues.

2 participants

@kares @headius