search

cretz / stackparam

JVM agent to add method parameters to Java stack traces
MIT License
123 stars 10 forks source link

non deterministic crash / hangs #1

Open retronym opened 7 years ago

retronym commented 7 years ago

Thanks for writing this agent, its a great intro to JVMTI for would be tinkerers (like me!)

I've tried out the agent in the Scala compiler. I've experienced a race condition of some sort.

Invocation:

 /Library/Java/JavaVirtualMachines/jdk1.8.0_112.jdk/Contents/Home/bin/java -Xmx256M -Xms32M -agentpath:/code/stackparam/target/release/libstackparam.dylib -Xbootclasspath/a:/Users/jz/scala/2.12.1/lib/jline-2.14.1.jar:/Users/jz/scala/2.12.1/lib/scala-compiler.jar:/Users/jz/scala/2.12.1/lib/scala-library.jar:/Users/jz/scala/2.12.1/lib/scala-parser-combinators_2.12-1.0.4.jar:/Users/jz/scala/2.12.1/lib/scala-reflect.jar:/Users/jz/scala/2.12.1/lib/scala-swing_2.12-2.0.0-M2.jar:/Users/jz/scala/2.12.1/lib/scala-xml_2.12-1.0.6.jar:/Users/jz/scala/2.12.1/lib/scalap-2.12.1.jar -classpath '""' -Dscala.home=/Users/jz/scala/2.12.1 -Dscala.usejavacp=true -Denv.emacs= scala.tools.nsc.Main -Ydebug -J-agentpath:/code/stackparam/target/release/libstackparam.dylib /tmp/a.scala

(or, brew install scala; scalac -J-agentpath:... test.scala)

Success:

scala.reflect.internal.Symbols$CyclicReference: illegal cyclic reference involving method foo
    at scala.reflect.internal.Symbols$Symbol.$anonfun$info$3(Symbols.scala:0) [this=method foo]
    at scala.Function0.apply$mcV$sp(Function0.scala:0) [this=method foo]
    at scala.reflect.internal.Symbols$Symbol.lock(Symbols.scala:0) [this=scala.tools.nsc.typechecker.Typers$Typer$$anon$2@3..., tree=C.this.foo, sym=method foo, pre=C.this.type, site=C.this]
    at scala.reflect.internal.Symbols$Symbol.info(Symbols.scala:0) [this=scala.tools.nsc.typechecker.Typers$NormalTyper@2e3..., tree=C.this.foo, sym=method foo, pre=C.this.type, site=C.this]
    at scala.reflect.internal.Symbols$Symbol.cookJavaRawInfo(Symbols.scala:0) [this=scala.tools.nsc.typechecker.Typers$NormalTyper@2e3..., tree=foo, name=foo, mode$4=1, pt$5=?]

...
  /tmp/a.scala, sources=List(a.scala)]
    at scala.tools.nsc.Global$Run.compile(Global.scala:0) [this=scalac Run for:
  /tmp/a.scala, filenames=List(/tmp/a.scala)]
    at scala.tools.nsc.MainClass.doCompile(Main.scala:0) [this=scala.tools.nsc.Main$@548ad73b, compiler=scala.tools.nsc.Global@4c762604]
    at scala.tools.nsc.Driver.process(Driver.scala:0) [this=scala.tools.nsc.Main$@548ad73b, args=[-Ydebug, -J-agentpath:/code/stackparam/target/rel...]
    at scala.tools.nsc.Driver.main(Driver.scala:0) [this=scala.tools.nsc.Main$@548ad73b, args=[-Ydebug, -J-agentpath:/code/stackparam/target/rel...]
    at scala.tools.nsc.Main.main(Main.scala:0) [arg0=[-Ydebug, -J-agentpath:/code/stackparam/target/rel...]
/tmp/a.scala:1: error: recursive method foo needs result type
class C { def foo = bar; def bar = foo }
                                   ^

Hang

Sample: https://gist.github.com/df539bec027279148d0ca0e7ba3d5bea Spindump: https://gist.github.com/79c6a311c70a4d66613c08e1a1d560aa

Excerpt from GC thread:

    +                                     2513 GenerateOopMap::verify_error(char const*, ...)  (in libjvm.dylib) + 237  [0x10e62fae7]
    +                                       2513 Exceptions::new_exception(Thread*, Symbol*, char const*, Exceptions::ExceptionMsgToUtf8Mode)  (in libjvm.dylib) + 24  [0x10e5ec0e8]
    +                                         2513 Exceptions::new_exception(Thread*, Symbol*, char const*, Handle, Handle, Handle, Exceptions::ExceptionMsgToUtf8Mode)  (in libjvm.dylib) + 181  [0x10e5ec019]
    +                                           2513 java_lang_String::create_from_str(char const*, Thread*)  (in libjvm.dylib) + 59  [0x10e69f38d]

Linking invokedynamic callsites which (sadly) use exceptions as control flow, likely very early in startup.

    +                                                                               2513 MethodHandles::resolve_MemberName(Handle, KlassHandle, Thread*)  (in libjvm.dylib) + 914  [0x10e8027ae]
    +                                                                                 2513 LinkResolver::resolve_static_call(CallInfo&, KlassHandle&, Symbol*, Symbol*, KlassHandle, bool, bool, Thread*)  (in libjvm.dylib) + 83  [0x10e778859]
    +                                                                                   2513 LinkResolver::linktime_resolve_static_method(methodHandle&, KlassHandle, Symbol*, Symbol*, KlassHandle, bool, Thread*)  (in libjvm.dylib) + 79  [0x10e775285]
    +                                                                                     2513 LinkResolver::resolve_method(methodHandle&, KlassHandle, Symbol*, Symbol*, KlassHandle, bool, bool, Thread*)  (in libjvm.dylib) + 651  [0x10e77481b]
    +                                                                                       2513 Exceptions::_throw_msg_cause(Thread*, char const*, int, Symbol*, char const*, Handle)  (in libjvm.dylib) + 46  [0x10e5ec64e]
    +                                                                                         2513 Exceptions::_throw_msg_cause(Thread*, char const*, int, Symbol*, char const*, Handle, Handle, Handle)  (in libjvm.dylib) + 114  [0x10e5ec5fe]
    +                                                                                           2513 Exceptions::new_exception(Thread*, Symbol*, char const*, Handle, Handle, Handle, Exceptions::ExceptionMsgToUtf8Mode)  (in libjvm.dylib) + 361  [0x10e5ec0cd]
    +                                                                                             2513 Exceptions::new_exception(Thread*, Symbol*, Symbol*, JavaCallArguments*, Handle, Handle, Handle)  (in libjvm.dylib) + 40  [0x10e5ebe6e]
    +                                                                                               2513 Exceptions::new_exception(Thread*, Symbol*, Symbol*, JavaCallArguments*, Handle, Handle)  (in libjvm.dylib) + 199  [0x10e5ebd73]
    +                                                                                                 2513 JavaCalls::call_special(JavaValue*, KlassHandle, Symbol*, Symbol*, JavaCallArguments*, Thread*)  (in libjvm.dylib) + 252  [0x10e69804a]
    +                                                                                                   2513 JavaCalls::call_helper(JavaValue*, methodHandle*, JavaCallArguments*, Thread*)  (in libjvm.dylib) + 1710  [0x10e697bd2]
    +                                                                                                     2513 ???  (in <unknown binary>)  [0x1172787a7]
    +                                                                                                       2513 ???  (in <unknown binary>)  [0x1172802bd]
    +                                                                                                         2513 ???  (in <unknown binary>)  [0x1172802bd]
    +                                                                                                           2513 ???  (in <unknown binary>)  [0x1172802bd]
    +                                                                                                             2513 ???  (in <unknown binary>)  [0x1172802bd]
    +                                                                                                               2513 ???  (in <unknown binary>)  [0x117280040]
    +                                                                                                                 2513 ???  (in <unknown binary>)  [0x117280040]
    +                                                                                                                   2513 ???  (in <unknown binary>)  [0x11728f9f4]
    +                                                                                                                     2513 Java_java_lang_Throwable_fillInStackTrace  (in libjava.dylib) + 20  [0x10f3628e2]
    +                                                                                                                       2513 JVM_FillInStackTrace  (in libjvm.dylib) + 106  [0x10e6f987d]
    +                                                                                                                         2513 java_lang_Throwable::fill_in_stack_trace(Handle, methodHandle)  (in libjvm.dylib) + 159  [0x10e69db9b]
    +                                                                                                                           2513 java_lang_Throwable::fill_in_stack_trace(Handle, methodHandle, Thread*)  (in libjvm.dylib) + 211  [0x10e69d679]
    +                                                                                                                             2513 BacktraceBuilder::BacktraceBuilder(Thread*)  (in libjvm.dylib) + 71  [0x10e69fb21]
    +                                                                                                                               2513 BacktraceBuilder::expand(Thread*)  (in libjvm.dylib) + 86  [0x10e69f730]
    +                                                                                                                                 2513 CollectedHeap::array_allocate(KlassHandle, int, int, Thread*)  (in libjvm.dylib) + 43  [0x10e45cbed]
    +                                                                                                                                   2513 CollectedHeap::common_mem_allocate_noinit(KlassHandle, unsigned long, Thread*)  (in libjvm.dylib) + 140  [0x10e45c9f2]
    +                                                                                                                                     2513 ParallelScavengeHeap::mem_allocate(unsigned long, bool*)  (in libjvm.dylib) + 518  [0x10e846e6e]
    +                                                                                                                                       2513 VMThread::execute(VM_Operation*)  (in libjvm.dylib) + 269  [0x10e961469]
    +                                                                                                                                         2513 Monitor::wait(bool, long, bool)  (in libjvm.dylib) + 222  [0x10e80e0fc]
    +                                                                                                                                           2513 Monitor::IWait(Thread*, long)  (in libjvm.dylib) + 168  [0x10e80df2c]
    +                                                                                                                                             2513 ParkCommon(ParkEvent*, long)  (in libjvm.dylib) + 42  [0x10e80d656]
    +                                                                                                                                               2513 os::PlatformEvent::park()  (in libjvm.dylib) + 192  [0x10e83054a]
    +                                                                                                                                                 2513 _pthread_cond_wait  (in libsystem_pthread.dylib) + 712  [0x7fff8bc4c96a]
    +                                                                                                                                                   2513 __psynch_cvwait  (in libsystem_kernel.dylib) + 10  [0x7fff8bb62c86]

Crash

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x000000010d58d2c3, pid=50118, tid=0x0000000000002703
#
# JRE version: Java(TM) SE Runtime Environment (8.0_112-b16) (build 1.8.0_112-b16)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.112-b16 mixed mode bsd-amd64 compressed oops)
# Problematic frame:
# V  [libjvm.dylib+0x18d2c3]  void oop_store<unsigned int>(unsigned int*, oopDesc*)+0x93
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /Users/jz/code/stackparam/hs_err_pid50118.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
Abort trap: 6

hs_err_pid50118.log

retronym commented 7 years ago

Increasing -Xms to a high value seems to work around the issue.

cretz commented 7 years ago

Thanks for the report! I'll add some scala, kotlin, etc tests and investigate