5 Replies Latest reply: Jun 12, 2011 11:24 PM by 815982 RSS

    Threads freeze on JVM internal lock

    815982
      h3. Question
      We have a problem with an multithreaded application that runs on JVM 1.6 (/opt/jdk1.6.0_21): two threads seem to be locked on an internal JVM semaphore. We have no locks on that code (even on superclasses).

      Is there any way to guess a solution for this problem?

      h3. Data
      h5. Java thread dump
      The java Threads are (notice the Object.wait() and RUNNABLE incoherent states):
      "Thread-2577696" prio=10 tid=0x08b76c00 nid=0x8f3 in Object.wait() [0x2f439000]
         java.lang.Thread.State: RUNNABLE
           at naf.arquitectura.DatoEnArray.<clinit>(DatoEnArray.java:21)
           at atclib.copy.CPY_CRPEE032.<init>(CPY_CRPEE032.java:15)
           at com.atcanet.impresor.comun.accesoDatos.AccesoDatosEtiquetaCorreo.darDomicilioPersona(AccesoDatosEtiquetaCorreo.java:312)
           at com.atcanet.impresor.separador.procesador.EtiquetaCorreo.domicilioPersona(EtiquetaCorreo.java:280)
           at com.atcanet.impresor.separador.procesador.EtiquetaCorreo.procesar(EtiquetaCorreo.java:106)
           at com.atcanet.impresor.separador.procesador.BloqueProcesamiento.ejecutarProceso(BloqueProcesamiento.java:37)
           at com.atcanet.impresor.separador.procesa
      
      "Thread-2577700" prio=10 tid=0x0ab44c00 nid=0x8f7 in Object.wait() [0x2f47b000]
         java.lang.Thread.State: RUNNABLE
           at atclib.copy.CPY_CRSRB080.<init>(CPY_CRSRB080.java:16)
           at com.atcanet.impresor.comun.accesoDatos.AccesoDatosEtiquetaCorreo.obtenerClaveImpresion(AccesoDatosEtiquetaCorreo.java:591)
           at com.atcanet.impresor.separador.procesador.ControlComunicadosResumen.procesarComResumen(ControlComunicadosResumen.java:136)
           at com.atcanet.impresor.separador.procesador.ControladorDatos.procesar(ControladorDatos.java:299)
           at com.atcanet.impresor.separador.procesador.BloqueProcesamiento.ejecutarProceso(BloqueProcesamiento.java:37)
           at com.atcanet.impresor.separador.procesador.LanzadorProceso.run(LanzadorProceso.java:82)
      h5. Native thread dump
      A "jstack -m" dump with native threads of 2291 and 2295 shows this (note the ObjectSynchronizer19waitUninterruptibly):
      ----------------- 2291 -----------------
      0xb7f7f402          ????????
      0xb7942ee5     _ZN2os13PlatformEvent4parkEv + 0xe5
      0xb79ff15b     _ZN13ObjectMonitor4waitExbP6Thread + 0x5fb
      0xb79fc513     _ZN18ObjectSynchronizer19waitUninterruptiblyE6HandlexP6Thread + 0x53
      0xb7739447     _ZN13instanceKlass15initialize_implE19instanceKlassHandleP6Thread + 0x77
      0xb7738bc8     _ZN13instanceKlass10initializeEP6Thread + 0x58
      0xb7753cd6     _ZN18InterpreterRuntime4_newEP10JavaThreadP19constantPoolOopDesci + 0xc6
      0xb4364da4     * naf.arquitectura.DatoEnArray.<clinit>() bci:0 line:21 (Interpreted frame)
      0xb435234c     <StubRoutines>
      0xb775e920     _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallArgumentsP6Thread + 0x190
      0xb79423a8     _ZN2os20os_exception_wrapperEPFvP9JavaValueP12methodHandleP17JavaCallArgumentsP6ThreadES1_S3_S5_S7_ + 0x18
      0xb775e77f     _ZN9JavaCalls4callEP9JavaValue12methodHandleP17JavaCallArgumentsP6Thread + 0x2f
      0xb773a8f6     _ZN13instanceKlass27call_class_initializer_implE19instanceKlassHandleP6Thread + 0xb6
      0xb7739681     _ZN13instanceKlass15initialize_implE19instanceKlassHandleP6Thread + 0x2b1
      0xb7738bc8     _ZN13instanceKlass10initializeEP6Thread + 0x58
      0xb77398dc     _ZN13instanceKlass15initialize_implE19instanceKlassHandleP6Thread + 0x50c
      0xb7738bc8     _ZN13instanceKlass10initializeEP6Thread + 0x58
      0xb7753cd6     _ZN18InterpreterRuntime4_newEP10JavaThreadP19constantPoolOopDesci + 0xc6
      0xb4364da4     * atclib.copy.CPY_CRPEE032.<init>() bci:11 line:15 (Interpreted frame)
      0xb435508d     * com.atcanet.impresor.comun.accesoDatos.AccesoDatosEtiquetaCorreo.darDomicilioPersona(java.lang.String, java.lang.String, java.lang.String, java.lang.String) bci:71 line:312 (Interpreted frame)
      0xb4354f27     * com.atcanet.impresor.separador.procesador.EtiquetaCorreo.domicilioPersona(java.lang.String, java.lang.String, java.lang.String, java.lang.String) bci:9 line:280 (Interpreted frame)
      0xb435508d     * com.atcanet.impresor.separador.procesador.EtiquetaCorreo.procesar(java.lang.Object[]) bci:94 line:106 (Interpreted frame)
      0xb4355403     * com.atcanet.impresor.separador.procesador.BloqueProcesamiento.ejecutarProceso(int, java.lang.Object[]) bci:19 line:37 (Interpreted frame)
      0xb4354f27     * com.atcanet.impresor.separador.procesador.LanzadorProceso.run() bci:33 line:82 (Interpreted frame)
      0xb435234c     <StubRoutines>
      0xb775e920     _ZN9JavaCalls11call_helperEP9JavaValueP12methodHandleP17JavaCallArgumentsP6Thread + 0x190
      0xb79423a8     _ZN2os20os_exception_wrapperEPFvP9JavaValueP12methodHandleP17JavaCallArgumentsP6ThreadES1_S3_S5_S7_ + 0x18
      0xb775e127     _ZN9JavaCalls12call_virtualEP9JavaValue11KlassHandle12symbolHandleS3_P17JavaCallArgumentsP6Thread + 0xb7
      0xb775e1da     _ZN9JavaCalls12call_virtualEP9JavaValue6Handle11KlassHandle12symbolHandleS4_P6Thread + 0x6a
      0xb77de965     _Z12thread_entryP10JavaThreadP6Thread + 0xa5
      0xb7a3259e     _ZN10JavaThread3runEv + 0x11e
      0xb794389e     _Z10java_startP6Thread + 0x14e
      0x00b7d49b     start_thread + 0xcb
      ----------------- 2295 -----------------
      0xb7f7f402          ????????
      0xb7942ee5     _ZN2os13PlatformEvent4parkEv + 0xe5
      0xb79ff15b     _ZN13ObjectMonitor4waitExbP6Thread + 0x5fb
      0xb79fc513     _ZN18ObjectSynchronizer19waitUninterruptiblyE6HandlexP6Thread + 0x53
      0xb7739447     _ZN13instanceKlass15initialize_implE19instanceKlassHandleP6Thread + 0x77
      0xb7738bc8     _ZN13instanceKlass10initializeEP6Thread + 0x58
      0xb77398dc     _ZN13instanceKlass15initialize_implE19instanceKlassHandleP6Thread + 0x50c
      0xb7738bc8     _ZN13instanceKlass10initializeEP6Thread + 0x58
      0xb7753cd6     _ZN18InterpreterRuntime4_newEP10JavaThreadP19constantPoolOopDesci + 0xc6
      0xb4364da4     * atclib.copy.CPY_CRSRB080.<init>() bci:16 line:16 (Interpreted frame)
      0xb435508d     * com.atcanet.impresor.comun.accesoDatos.AccesoDatosEtiquetaCorreo.obtenerClaveImpresion(java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.String, org.atca.grid.GridJobContext) bci:35 line:591 (Interpreted frame)
      0xb4354f27     * com.atcanet.impresor.separador.procesador.ControlComunicadosResumen.procesarComR
      h5. The classes

      As you can see above, the threads are frozen on DatoEnArray:21 and CPY_CRSRB080:16
      19: public abstract class DatoEnArray extends Dato                                                                                                                                              
      20: {                                                                                                                                                                                           
      21:   protected static final DatoEnArray REDEFINE_GENERICO = new Texto("REDEFINE_GENERICO");                                                                                                                                
                                                                                                                                                                                             
      10: public class CPY_CRSRB080 extends CopyRutina                                                                                                                                                
      11: {                                                                                                                                                                                           
      12:   private String nombre = "CRSRB080";                                                                                                                                                       
      13:                                                                                                                                                                                             
      14:                                                                                                                                                                                             
      15:   public TextoCompuesto NIVEL_01 = null;                                                                                                                                                    
      16:   public Texto CODPOST = new Texto(5);             
        • 1. Re: Threads freeze on JVM internal lock
          802316
          Class loading and calling of the initialiser block is implicitly single threads. If you are loading the class in one thread, every other thread which attempt to use that class has to wait until it has finished.

          It is possible to get into a deadoad with these implicit lock in theory, however I have never seen this happen in practice.

          e.g.
          If you start a thread in a static initialiser block and wait for that thread to complete, but the thread needs the class you are loading, you get a deadlock.
          • 2. Re: Threads freeze on JVM internal lock
            815982
            Peter Lawrey wrote:
            Class loading and calling of the initialiser block is implicitly single threads. If you are loading the class in one thread, every other thread which attempt to use that class has to wait until it has finished.
            When you say this you rather mean "class instancing" instance of "class loading"?
            e.g.
            If you start a thread in a static initialiser block and wait for that thread to complete, but the thread needs the class you are loading, you get a deadlock.
            I dont start the thread in such an "initialiser block", Moreover, the class (DatoEnArray) is already loaded, instanced and is on initialization phase.

            I think the problem could be around the native code "instanceKlass->initialize", about some weird "initialization" locking???

            Thanks.
            • 3. Re: Threads freeze on JVM internal lock
              802316
              I wouldn't say the class has been loaded until it is initialised. You can see the DatoEnArray is still being initialised.
              • 4. Re: Threads freeze on JVM internal lock
                jschellSomeoneStoleMyAlias
                protected static final DatoEnArray REDEFINE_GENERICO = new Texto("REDEFINE_GENERICO");
                This results in a static initializer. That is how the compiler creates the code.
                public Texto CODPOST = new Texto(5);
                This results in an initializer.
                public abstract class DatoEnArray extends Dato
                {                                                                                                                                                                                          
                protected static final DatoEnArray REDEFINE_GENERICO = new Texto ("REDEFINE_GENERICO");
                Myself I can't see that idiom is going to result in anything that is maintainable.

                And I would expect it to cause problems.

                I wouldn't be surprised if you set that to null above that the block would go away.
                • 5. Re: Threads freeze on JVM internal lock
                  815982
                  Peter Lawrey wrote:
                  I wouldn't say the class has been loaded until it is initialised. You can see the DatoEnArray is still being initialised.
                  Yes, you were right. Sorry my blindness because I was unable to see what you said about the static block. I have made a test case and I got the same scenario.

                  At the same time you both helped me about the design error on this class (DatoEnArray) that points to a child class. Its a beginner error.

                  Thank you.

                  Edited by: PacoBelloso on Jun 12, 2011 11:24 PM