488 words

OEM Enhancer causing Jenkins job to freeze

#1
2013-09-16 05:51

Hi all,

We are using ODB enhancer in one of our jobs on jenkins, built via ant. Recently we started to encounter situation, where this job's execution gets stuck for ever on Jenkins. This is causing us a lot of problems with our CI.

<java classpath="${project.root.dir}lib/*;${project.root.dir}/temp/*;${dist.dir}" classname="com.objectdb.Enhancer" fork="true">
    <arg line="-s ${dist.dir}/our/entities/package/"/>
</java>

Is it possible to enable some detailed logging for enhancer? To see where exactly it gets stuck during it's execution?

Also, our Jenkins machine doesn't have access to internet, could this be an issue?

 

Thank you

Maruta
Maruta's picture
Joined on 2013-03-20
User Post #23
#2
2013-09-16 08:38

Usually the Enhancer doesn't need access to the Internet. Sometimes, however, an attempt to access the Internet may happen during xml validation by the Java XML parser, if external XML schema is specified in XML files.

Please try to generate a Java thread dump that will show where exactly the process is stuck.

 

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
support
support's picture
Joined on 2010-05-03
User Post #1,690
#3
2013-10-07 08:29

Hello,

we have succeeded to simulate the problem again and have created dump for you.

I have attatched the thread dump listing.

I you need the whole dump I can provide it.

 

Thank you

Marta

Maruta
Maruta's picture
Joined on 2013-03-20
User Post #24
#4
2013-10-09 22:05

The relevant stack trace in this thread dump is:

"main" prio=5 tid=1 RUNNABLE
at org.apache.log4j.Priority.<clinit>(Priority.java:45)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:169)
at org.apache.commons.logging.impl.Log4JLogger.class$(Log4JLogger.java:55)
    Local Variable: java.lang.String#20504
at org.apache.commons.logging.impl.Log4JLogger.<clinit>(Log4JLogger.java:80)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:247)
at org.apache.commons.logging.impl.LogFactoryImpl.createLogFromClass(LogFactoryImpl.java:1081)
    Local Variable: java.lang.String#20480
    Local Variable: java.lang.Object[]#14005
    Local Variable: sun.misc.Launcher$AppClassLoader#1
at org.apache.commons.logging.impl.LogFactoryImpl.discoverLogImplementation(LogFactoryImpl.java:914)
at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:604)
at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:336)
    Local Variable: java.lang.String#20429
at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:310)
    Local Variable: org.apache.commons.logging.impl.LogFactoryImpl#1
at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:685)
at eu.ysoft.commons.logging.LogFactory.getLog(LogFactory.java:32)
at eu.ysoft.safeq.core.cache.entity.CacheableDriverProperty.<clinit>(CacheableDriverProperty.java:24)
at sun.misc.Unsafe.ensureClassInitialized(Native Method)
at sun.reflect.UnsafeFieldAccessorFactory.newFieldAccessor(UnsafeFieldAccessorFactory.java:25)
    Local Variable: class java.net.InetSocketAddress
at sun.reflect.ReflectionFactory.newFieldAccessor(ReflectionFactory.java:122)
    Local Variable: sun.reflect.ReflectionFactory#1
at java.lang.reflect.Field.acquireFieldAccessor(Field.java:918)
at java.lang.reflect.Field.getFieldAccessor(Field.java:899)
at java.lang.reflect.Field.get(Field.java:358)
at com.objectdb.o.ANT.r(ANT.java:198)
    Local Variable: java.lang.String#22728
at com.objectdb.o.ANT.q(ANT.java:154)
    Local Variable: java.lang.reflect.Field#627
    Local Variable: java.lang.reflect.Field[]#39
at com.objectdb.o.SCM.r(SCM.java:229)
    Local Variable: com.objectdb.o.ANT#1
    Local Variable: class eu.ysoft.safeq.core.cache.entity.CacheableDriverProperty
at com.objectdb.o.JEW.aK(JEW.java:185)
    Local Variable: com.objectdb.o.SCM#1
at com.objectdb.o.JEL.A(JEL.java:433)
    Local Variable: com.objectdb.o.JEW[]#1
    Local Variable: java.lang.String#17766
    Local Variable: com.objectdb.o.ALS#34
    Local Variable: com.objectdb.o.ALS#33
    Local Variable: com.objectdb.o.JEW#8
    Local Variable: com.objectdb.o.JEL#1
at com.objectdb.o.JEN.k(JEN.java:93)
    Local Variable: com.objectdb.o.JEN#1
at com.objectdb.Enhancer.main(Enhancer.java:32)
    Local Variable: java.lang.String[]#1275

ObjectDB uses Java reflection to analyze classes for enhancement. The thread dump was taken while the Enhancer was analyzing the class eu.ysoft.safeq.core.cache.entity.CacheableDriverProperty.

Maybe something in that class causes the problem. The stack trace mentions InetSocketAddress (maybe as the type of one of the fields), and maybe it is related to network operations. Initialization of the classes for Java reflection also includes running a static initializer of eu.ysoft.safeq.core.cache.entity.CacheableDriverProperty with many log initializations.

The exact problem is unclear, but you can see in the stack trace that the operation is inside your code. Your application code is invoked by ObjectDB (through Java reflection which runs the static initializer of CacheableDriverProperty), and maybe that code is not expected to run in that environment during enhancement.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
support
support's picture
Joined on 2010-05-03
User Post #1,710
#5
2013-10-11 08:03

Hi,

We found out that issue is caused by classloader deadlock. Problem occurs during logging class initialization from static block(variable) when there are multiple logging frameworks present on classpath.

Nice description of this issue can be found here: http://stackoverflow.com/questions/15543521/mixed-usage-of-log4j-and-commons-logging-causes-a-class-loading-deadlock

Maruta
Maruta's picture
Joined on 2013-03-20
User Post #25
#6
2013-10-11 10:46

This is interesting, thank you for this update.

Since now we know that this deadlock is not related to ObjectDB, strange that you noticed it only during enhancement and not when you start your application (since it may happen every time that this class is loaded and initialized).

Anyway, fixing this should be good for both enhancement and application initialization.

ObjectDB Support
ObjectDB - Fast Object Database for Java (JPA/JDO)
support
support's picture
Joined on 2010-05-03
User Post #1,712

Post Reply

Please read carefully the posting instructions - before posting to the ObjectDB website.

  • You may have to disable pop up blocking in order to use the toolbar (e.g. in Chrome).
  • Use ctrl + right click to open the browser context menu in the editing area (e.g. for using a browser spell checker).
  • To insert formatted lines (e.g. Java code, stack trace) - select a style in the toolbar and then insert the text in the new created block.
  • Avoid overflow of published source code examples by breaking long lines.
  • You may mark in paragraph code words (e.g. class names) with the code style (can be applied by ctrl + D).
  • Long stack traces (> 50 lines) and complex source examples (> 100 lines) should be posted as attachments.
Attachments:
Maximum file size: 32 MB
Cancel