Skip to content

Instantly share code, notes, and snippets.

@ninkibah
Created September 11, 2015 15:46
Show Gist options
  • Save ninkibah/c8a05f85afd0f01eca34 to your computer and use it in GitHub Desktop.
Save ninkibah/c8a05f85afd0f01eca34 to your computer and use it in GitHub Desktop.
Profile output running one test file under jruby 1.7.22
joconnor@joconnor-ThinkPad-T410:~/NetBeansProjects/XPesa$ RAILS_ENV=test JAVA_OPTS=-Xprof jruby -Itest --dev /home/joconnor/NetBeansProjects/XPesa/test/unit/payments/payment_maker_test.rb
Emptying /home/joconnor/NetBeansProjects/XPesa/test/reports
NOTE: ActiveRecord 4.2 is not (yet) fully supported by AR-JDBC, please help us finish 4.2 support - check http://bit.ly/jruby-42 for starters
# Running tests with run options --seed 13092:
...........
Flat profile of 3,75 secs (339 total ticks): Ruby-0-Thread-2: /home/joconnor/.rvm/gems/jruby-1.7.22@xpesa/gems/minitest-5.7.0/lib/minitest/parallel.rb:28
Thread-local ticks:
100,0% 339 Blocked (of total)
Flat profile of 3,75 secs (339 total ticks): Ruby-0-Thread-1: /home/joconnor/.rvm/gems/jruby-1.7.22@xpesa/gems/minitest-5.7.0/lib/minitest/parallel.rb:28
Interpreted + native Method
100,0% 1 + 0 java.util.Vector.iterator
100,0% 1 + 0 Total interpreted
Thread-local ticks:
99,7% 338 Blocked (of total)
Finished tests in 3.744000s, 2.9380 tests/s, 7.2115 assertions/s.
11 tests, 27 assertions, 0 failures, 0 errors, 0 skips
Writing XML reports to /home/joconnor/NetBeansProjects/XPesa/test/reports
Flat profile of 25,16 secs (2122 total ticks): main
Interpreted + native Method
2,2% 0 + 46 java.net.SocketInputStream.socketRead0
0,4% 1 + 7 java.io.UnixFileSystem.list
0,3% 6 + 0 org.jruby.ext.psych.PsychParser.parse
0,2% 0 + 5 sun.nio.ch.FileDispatcherImpl.read0
0,2% 0 + 4 java.io.FileInputStream.readBytes
0,2% 0 + 4 java.util.zip.ZipFile.read
0,1% 2 + 1 java.lang.ClassLoader.defineClass1
0,1% 3 + 0 org.jruby.RubyFile.openFile19
0,1% 3 + 0 org.jruby.ext.ffi.Factory.init
0,1% 0 + 2 java.lang.Package.getSystemPackage0
0,1% 0 + 2 java.io.FileInputStream.close0
0,1% 0 + 2 java.io.UnixFileSystem.getBooleanAttributes0
0,1% 0 + 2 java.lang.Throwable.fillInStackTrace
0,1% 0 + 2 java.io.UnixFileSystem.canonicalize0
0,1% 1 + 1 java.lang.Class.forName0
0,1% 2 + 0 org.jruby.parser.BlockStaticScope.<init>
0,1% 2 + 0 org.joni.ArrayCompiler.prepare
0,1% 2 + 0 org.jruby.RubyEnumerable.injectCommon
0,1% 2 + 0 org.jruby.ast.ArrayNode.interpretPrimitive
0,1% 2 + 0 org.jruby.util.ConvertBytes.intToUnsignedByteList
0,1% 2 + 0 org.jruby.runtime.marshal.UnmarshalStream.unmarshalString
0,1% 2 + 0 org.jruby.ast.DRegexpNode.buildDRegexpString19
0,1% 2 + 0 org.jruby.ext.socket.SocketLibrary.load
0,1% 2 + 0 arjdbc.jdbc.RubyJdbcConnection.setupColumns
0,1% 2 + 0 org.jruby.gen.org$jruby$RubyModule$POPULATOR.populate
17,1% 279 + 83 Total interpreted (including elided)
Compiled + native Method
5,2% 0 + 111 org.jruby.runtime.DynamicScope.newDynamicScope
3,6% 4 + 73 org.jruby.ast.IfNode.interpret
1,2% 2 + 23 org.jruby.ast.NewlineNode.interpret
0,5% 10 + 0 org.jruby.runtime.callsite.CachingCallSite.call
0,4% 9 + 0 org.jruby.ast.InstVarNode.definition
0,4% 9 + 0 org.jruby.runtime.ThreadContext.pushCallFrame
0,4% 8 + 0 java.util.concurrent.ConcurrentHashMap.get
0,3% 7 + 0 org.jruby.runtime.opto.ConstantCache.isCached
0,3% 6 + 1 org.jruby.RubyClass.addInvalidatorsAndFlush
0,3% 6 + 0 org.jruby.ast.LocalVarNode.interpret
0,3% 6 + 0 org.jruby.RubyModule.invalidateCacheDescendants
0,2% 5 + 0 org.jruby.runtime.opto.GenerationInvalidator.invalidate
0,2% 2 + 3 org.jruby.ast.BlockNode.interpret
0,2% 5 + 0 org.jruby.RubyModule.searchMethodInner
0,2% 5 + 0 org.jruby.lexer.yacc.InputStreamLexerSource.read
0,2% 5 + 0 org.jruby.runtime.Interpreted19Block.yield
0,2% 4 + 1 org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD
0,2% 5 + 0 org.jruby.RubyHash.internalPutSmall
0,2% 5 + 0 org.jruby.internal.runtime.methods.InterpretedMethod.call
0,2% 4 + 1 org.jruby.internal.runtime.methods.InterpretedMethod.call
0,2% 4 + 0 org.jruby.RubyModule$KindOf.isKindOf
0,2% 4 + 0 org.jruby.ast.InstVarNode.getVariable
0,2% 4 + 0 org.jruby.runtime.ThreadContext.getRubyClass
0,2% 4 + 0 org.jruby.runtime.ThreadContext.preMethodFrameAndScope
0,2% 4 + 0 org.jruby.util.PerlHash.hash
23,8% 251 + 253 Total compiled (including elided)
Stub + native Method
14,1% 0 + 299 java.lang.String.intern
14,0% 23 + 274 java.io.UnixFileSystem.getBooleanAttributes0
5,1% 0 + 109 java.lang.Thread.isInterrupted
4,2% 0 + 90 java.lang.Object.clone
3,7% 0 + 78 java.net.SocketInputStream.socketRead0
3,1% 0 + 65 java.lang.System.identityHashCode
2,1% 0 + 45 java.io.FileInputStream.readBytes
1,9% 0 + 41 java.lang.Throwable.fillInStackTrace
1,6% 0 + 33 java.lang.Throwable.getStackTraceElement
0,9% 0 + 19 java.lang.Class.isAssignableFrom
0,7% 0 + 14 java.lang.Object.hashCode
0,7% 0 + 14 java.lang.System.arraycopy
0,7% 9 + 5 java.lang.ClassLoader.defineClass1
0,5% 0 + 11 java.net.SocketOutputStream.socketWrite0
0,4% 0 + 9 java.io.FileInputStream.close0
0,4% 0 + 8 com.kenai.jffi.Foreign.invokeN3O2
0,3% 0 + 6 jnr.posix.LinuxLibC$jnr$ffi$0.getpid
0,3% 0 + 6 java.lang.Thread.currentThread
0,2% 0 + 5 java.lang.Class.forName0
0,2% 0 + 5 java.util.zip.Inflater.inflateBytes
0,2% 0 + 5 java.util.zip.ZipFile.read
0,2% 0 + 4 sun.reflect.Reflection.getCallerClass
0,1% 0 + 3 java.lang.Class.getSuperclass
0,1% 0 + 3 java.lang.ClassLoader.findBootstrapClass
0,1% 0 + 3 java.lang.ClassLoader.findLoadedClass0
57,2% 34 + 1180 Total stub (including elided)
Thread-local ticks:
0,0% 1 Blocked (of total)
1,9% 41 Class loader
Flat profile of 0,00 secs (1 total ticks): DestroyJavaVM
Thread-local ticks:
100,0% 1 Blocked (of total)
Global summary of 25,17 seconds:
100,0% 2268 Received ticks
6,3% 143 Received GC ticks
15,2% 344 Compilation
0,0% 1 Deoptimization
0,0% 1 Other VM operations
1,8% 41 Class loader
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment