[#JRUBY-1475] trunk has broken c-call traces

JRuby

trunk has broken c-call traces

Created: 25/Oct/07 04:04 PM Updated: 16/Mar/08 10:15 PM

Component/s:

None

Affects Version/s:

None

Fix Version/s:

JRuby 1.1+

Time Tracking:

Not Specified

File Attachments:

factory.patch (5 kb)

Description

« Hide

The new mechanism for binding methods generates complete DynamicMethod implementations. Unfortunately, the generated code does not include c-call traces where it should. This has the effect of breaking c-call tracing on trunk.

We need to resolve this for 1.1. Honestly, I'm feeling more and more like there should be a startup flag to enable debugging, which we'd use to turn off optimizations like this...rather than having to constantly check for debug hooks at runtime when they'll never be used.

All

Comments

Work Log

Change History

Sort Order:

Ascending order - Click to sort in descending order

[ Permlink | « Hide ]

Peter Brant - 29/Oct/07 09:23 PM

Attached patch adds c-call/c-return traces to InvocationMethodFactory. Test case will be forthcoming (basically we need to make test_trace_func.rb work again).

[ Permlink | « Hide ]

Charles Oliver Nutter - 30/Oct/07 11:51 AM

Wow, ambitious of you to dig into ASM. I don't suppose you've run any perf numbers with this, have you?

Ideally in 1.1b1, but it's not critical for the beta.

[ Permlink | « Hide ]

Peter Brant - 30/Oct/07 12:12 PM

Not yet. I'll take a look after work though.

[ Permlink | « Hide ]

Peter Brant - 30/Oct/07 06:12 PM

Looks like it slows down method dispatch by about 5% with the server JVM or half that with the client JVM (constant tax, but twice as slow overall).

Server JVM with patch:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-server -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
  6.810000   0.000000   6.810000 (  6.810000)
  6.890000   0.000000   6.890000 (  6.890000)
  6.750000   0.000000   6.750000 (  6.750000)
  6.759000   0.000000   6.759000 (  6.759000)
  6.750000   0.000000   6.750000 (  6.750000)

Server JVM w/o patch:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-server -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
  6.660000   0.000000   6.660000 (  6.660000)
  6.499000   0.000000   6.499000 (  6.509000)
  6.410000   0.000000   6.410000 (  6.410000)
  6.419000   0.000000   6.419000 (  6.419000)
  6.409000   0.000000   6.409000 (  6.409000)

Client JVM with patch

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
 12.758000   0.000000  12.758000 ( 12.758000)
 12.909000   0.000000  12.909000 ( 12.909000)
 12.788000   0.000000  12.788000 ( 12.788000)
 12.768000   0.000000  12.768000 ( 12.768000)
 12.849000   0.000000  12.849000 ( 12.849000)

Client JVM w/o patch:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
 12.629000   0.000000  12.629000 ( 12.629000)
 12.528000   0.000000  12.528000 ( 12.528000)
 12.518000   0.000000  12.518000 ( 12.518000)
 12.528000   0.000000  12.528000 ( 12.528000)
 12.758000   0.000000  12.758000 ( 12.758000)

MRI:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>ruby bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
 12.528000   0.000000  12.528000 ( 14.911000)
 12.498000   0.000000  12.498000 ( 12.598000)
 12.508000   0.000000  12.508000 ( 12.598000)
 12.498000   0.000000  12.498000 ( 12.639000)
 12.618000   0.000000  12.618000 ( 12.788000)

(test was taken from bench_method_dispatch.rb)

[ Show » ]

Peter Brant - 30/Oct/07 06:12 PM Looks like it slows down method dispatch by about 5% with the server JVM or half that with the client JVM (constant tax, but twice as slow overall). Server JVM with patch:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-server -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
  6.810000   0.000000   6.810000 (  6.810000)
  6.890000   0.000000   6.890000 (  6.890000)
  6.750000   0.000000   6.750000 (  6.750000)
  6.759000   0.000000   6.759000 (  6.759000)
  6.750000   0.000000   6.750000 (  6.750000)

Server JVM w/o patch:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-server -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
  6.660000   0.000000   6.660000 (  6.660000)
  6.499000   0.000000   6.499000 (  6.509000)
  6.410000   0.000000   6.410000 (  6.410000)
  6.419000   0.000000   6.419000 (  6.419000)
  6.409000   0.000000   6.409000 (  6.409000)

Client JVM with patch

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
 12.758000   0.000000  12.758000 ( 12.758000)
 12.909000   0.000000  12.909000 ( 12.909000)
 12.788000   0.000000  12.788000 ( 12.788000)
 12.768000   0.000000  12.768000 ( 12.768000)
 12.849000   0.000000  12.849000 ( 12.849000)

Client JVM w/o patch:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>..\..\bin\jruby 
    -J-Djruby.jit.enabled=false bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
 12.629000   0.000000  12.629000 ( 12.629000)
 12.528000   0.000000  12.528000 ( 12.528000)
 12.518000   0.000000  12.518000 ( 12.518000)
 12.528000   0.000000  12.528000 ( 12.528000)
 12.758000   0.000000  12.758000 ( 12.758000)

MRI:

C:\eclipseWorkspaceQT\jruby_trunk\test\bench>ruby bench_method_native_only.rb
Test STI: 400k loops accessing a fixnum var and calling to_i 100 times
 12.528000   0.000000  12.528000 ( 14.911000)
 12.498000   0.000000  12.498000 ( 12.598000)
 12.508000   0.000000  12.508000 ( 12.598000)
 12.498000   0.000000  12.498000 ( 12.639000)
 12.618000   0.000000  12.618000 ( 12.788000)

(test was taken from bench_method_dispatch.rb)

[ Permlink | « Hide ]

Peter Brant - 02/Nov/07 08:50 PM

Please disregard patch. I have the bytecode transformation approach mentioned earlier mostly implemented. Will post for comments in a couple of days.

[ Permlink | « Hide ]

Charles Oliver Nutter - 07/Nov/07 12:38 AM

Peter: Looking forward to it.

[ Permlink | « Hide ]

Peter Brant - 09/Nov/07 09:14 PM

Patch + description posted to JRUBY-1531

[ Permlink | « Hide ]

Charles Oliver Nutter - 20/Dec/07 01:47 PM

Sorry, revisit this one more time and we'll get it in. Email me directly if you don't see action.

[ Permlink | « Hide ]

Charles Oliver Nutter - 14/Feb/08 02:39 PM

Punting to 1.1, but still waiting on a final version based on recent trunk. Peter, if you get around to this bug me until it's committed and we can put it to rest. Others: if you want to update this for trunk, it would be a big help.