ODE
  1. ODE
  2. ODE-943

NoClassDefFoundError for org.apache.log4j.helpers.AbsoluteTimeDateFormat in SimpleScheduler.doLoadImmediate() leads memory leak

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 1.3.5, 1.4
    • Fix Version/s: 1.3.6, 1.4
    • Labels:
      None
    • Environment:
      Ubuntu 11.04 64bit, Oracle JDK 1.6, Servicemix 4.3.0

      Description

      On a fresh installation of Servicemix 4.3.0 does not expose org.apache.log4j.helpers by default although Pax logging bundle contains this package. At line:707 of Ode_1.3.5 version and line:732 of trunk, AbsoluteTimeDateFormat f = new AbsoluteTimeDateFormat(); line leads to NoClassDefFoundError for org.apache.log4j.helpers.AbsoluteTimeDateFormat. As this error is a subclass of throwable, it is not caught in catch() block.

      This issue leads to huge memory leak under load as _processedSinceLastLoadTask.clear(); line can not be reached ever, 1 million requests will make your 1gb heap size drained and get your servicemix in a fullgc cycles.

      I worked around this issue by wrapping log4j jar into servicemix by karaf@ osgi:install -s wrap:mvn:log4j/log4j/1.2.13 , and restarting whole system.

      Also log4j dependencies are imported as resolution:optional in MANIFEST-MF in ode-jbi bundle.

      To reproduce;

      1 - reduce heap size in servicemix executable
      2 - add jvm option : -verbosegc to watch gc and fullgc cycles on karaf console or -Xloggc:somefile.out for tailing a file for output
      3 - set KARAF_DEBUG=true in case you want to debug and see _processedSinceLastLoadTask.size() shows increasing number of entries
      3 - download servicemix 4.3.0 from apache
      4 - in karaf console, features:install ode
      5 - deploy a simple bpel flow, features:install examples-ode-ping-pong
      6 - generate load either via JMeter or Soapui
      7 - take a heap dump either via jmap or via JConsole finding mbean com.sun.management->HotSpotDiagnostic-> operations --> dumpHeap(heapdump.snapshot) , you can find dump file under $SMX_HOME
      8 - analyse it via yourkit profiler or jprofiler, whatever suits you, you will see one object retain most of the memory, which is org/apache/ode/scheduler/simple/SimpleScheduler on object explorer window.

        Activity

        Hide
        Abdulkadir Yaman added a comment - - edited

        I worked around this issue by wrapping log4j dependency as a bundle in servicemix. More elegant solution would be to add a wrapper bundle entry for log4j library in jbi-karaf/src/main/resources/features.xml as follows;

        <features>
        <feature name="ode-core-deps" version="1.3.5">
        <feature>transaction</feature>
        <bundle>wrap:mvn:log4j/log4j/1.2.13</bundle>
        ...........
        ...........
        ............
        <bundle>
        mvn:org.apache.servicemix.bundles/org.apache.servicemix.bundles.saxon/9.1.0.8_1
        </bundle>
        <bundle>
        mvn:org.apache.geronimo.components/geronimo-connector/2.1.3
        </bundle>
        </feature>
        ........

        Currently servicemix acquires http://repo1.maven.org/maven2/org/apache/ode/ode-jbi-karaf/1.3.5/ode-jbi-karaf-1.3.5-features.xml to install necessary dependencies and core components(correct me if i am wrong). This also has to be changed if we want servicemix 4.3.0 version to work correctly. However i am not sure if changing existing/already uploaded files in repo1.maven is elegant or not.

        Show
        Abdulkadir Yaman added a comment - - edited I worked around this issue by wrapping log4j dependency as a bundle in servicemix. More elegant solution would be to add a wrapper bundle entry for log4j library in jbi-karaf/src/main/resources/features.xml as follows; <features> <feature name="ode-core-deps" version="1.3.5"> <feature>transaction</feature> <bundle>wrap:mvn:log4j/log4j/1.2.13</bundle> ........... ........... ............ <bundle> mvn:org.apache.servicemix.bundles/org.apache.servicemix.bundles.saxon/9.1.0.8_1 </bundle> <bundle> mvn:org.apache.geronimo.components/geronimo-connector/2.1.3 </bundle> </feature> ........ Currently servicemix acquires http://repo1.maven.org/maven2/org/apache/ode/ode-jbi-karaf/1.3.5/ode-jbi-karaf-1.3.5-features.xml to install necessary dependencies and core components(correct me if i am wrong). This also has to be changed if we want servicemix 4.3.0 version to work correctly. However i am not sure if changing existing/already uploaded files in repo1.maven is elegant or not.
        Hide
        Mateusz Nowakowski added a comment - - edited

        I have the same issue under Fuse ESB Enterprise 7.0.2 (aka Fuse ESB 4.5)

        There are several way to fix it:

        1. AbsolteTImeDateFormat can be freely removed as it is used only for loggin in debug mode. It can be replaced via inline SimpleDateFormat or so..
        2. Fix ODE Import-Packages OSGi section, everything is optional, but if fact most of packages are mandatory (like this org.apache.log4j.helpers in this case)
        Show
        Mateusz Nowakowski added a comment - - edited I have the same issue under Fuse ESB Enterprise 7.0.2 (aka Fuse ESB 4.5) There are several way to fix it: AbsolteTImeDateFormat can be freely removed as it is used only for loggin in debug mode. It can be replaced via inline SimpleDateFormat or so.. Fix ODE Import-Packages OSGi section, everything is optional, but if fact most of packages are mandatory (like this org.apache.log4j.helpers in this case)
        Hide
        Mateusz Nowakowski added a comment -

        Additional workaround:

        Create a fragment bundle and attach it to pax-loggging-servce. PaxLogiingService contains complete org.apache.log4j.helpers package (pax-logging-api as well but there is only one class)
        Mvn instructions are:
        <build>
        <plugins>
        <plugin>
        <groupId>org.apache.felix</groupId>
        <artifactId>maven-bundle-plugin</artifactId>
        <extensions>true</extensions>
        <configuration>
        <instructions>
        <Import-Package>!*</Import-Package>
        <Export-Package>
        org.apache.log4j.helpers;version=1.2.15
        </Export-Package>
        <Fragment-Host>org.ops4j.pax.logging.pax-logging-service</Fragment-Host>
        </instructions>
        </configuration>
        </plugin>
        </plugins>
        </build>

        and ODE works again,

        Show
        Mateusz Nowakowski added a comment - Additional workaround: Create a fragment bundle and attach it to pax-loggging-servce. PaxLogiingService contains complete org.apache.log4j.helpers package (pax-logging-api as well but there is only one class) Mvn instructions are: <build> <plugins> <plugin> <groupId>org.apache.felix</groupId> <artifactId>maven-bundle-plugin</artifactId> <extensions>true</extensions> <configuration> <instructions> <Import-Package>!*</Import-Package> <Export-Package> org.apache.log4j.helpers;version=1.2.15 </Export-Package> <Fragment-Host>org.ops4j.pax.logging.pax-logging-service</Fragment-Host> </instructions> </configuration> </plugin> </plugins> </build> and ODE works again,
        Hide
        Mateusz Nowakowski added a comment -

        After running the test with the workaround provider - there is still a memory leak.

        If the traffic is high, i mean that one of these condition in SimpleScheduler.doLoadImmediate() are fulfilled :

        line 683: if (_outstandingJobs.size() > _todoLimit/2) return true;
        or
        lines 687-694:
        // don't load more than we can chew
        final int batch = Math.min((int) (_immediateInterval * _tps / 1000), _todoLimit-_outstandingJobs.size());

        // jobs might have been enqueued by #addTodoOnCommit meanwhile
        if (batch<=0)

        { if (__log.isDebugEnabled()) __log.debug("Max capacity reached: "+_outstandingJobs.size()+" jobs dispacthed i.e. queued or being executed"); return true; }

        it is likely that line _processedSinceLastLoadTask.clear() is never executed, so the leak is the same.

        If the traffic goes down everything is cleaned - but it depends on the traffic profile and it is dangerous (potential OOM)

        There is another workaround:
        Turn off this "defence" mechanism by adding these lines :
        ode.scheduler.queueLength=2147483647
        ode.scheduler.transactionsPerSecond=1000
        to
        etc/org.apache.ode.jbi.cfg

        But in the end SimpleScheduler needs to rewritten b/c this mechanism is potential killer.

        Show
        Mateusz Nowakowski added a comment - After running the test with the workaround provider - there is still a memory leak. If the traffic is high, i mean that one of these condition in SimpleScheduler.doLoadImmediate() are fulfilled : line 683: if (_outstandingJobs.size() > _todoLimit/2) return true; or lines 687-694: // don't load more than we can chew final int batch = Math.min((int) (_immediateInterval * _tps / 1000), _todoLimit-_outstandingJobs.size()); // jobs might have been enqueued by #addTodoOnCommit meanwhile if (batch<=0) { if (__log.isDebugEnabled()) __log.debug("Max capacity reached: "+_outstandingJobs.size()+" jobs dispacthed i.e. queued or being executed"); return true; } it is likely that line _processedSinceLastLoadTask.clear() is never executed, so the leak is the same. If the traffic goes down everything is cleaned - but it depends on the traffic profile and it is dangerous (potential OOM) There is another workaround: Turn off this "defence" mechanism by adding these lines : ode.scheduler.queueLength=2147483647 ode.scheduler.transactionsPerSecond=1000 to etc/org.apache.ode.jbi.cfg But in the end SimpleScheduler needs to rewritten b/c this mechanism is potential killer.
        Hide
        Tammo van Lessen added a comment -

        The last comment is a new issue, shall I open a new one or do you, Mateusz want to do that? Do you have a patch handy already?

        I'm fixing the NoClassDefFoundError meanwhile.

        Show
        Tammo van Lessen added a comment - The last comment is a new issue, shall I open a new one or do you, Mateusz want to do that? Do you have a patch handy already? I'm fixing the NoClassDefFoundError meanwhile.
        Hide
        Tammo van Lessen added a comment -

        fixed in trunk and 1.3.6.x

        Show
        Tammo van Lessen added a comment - fixed in trunk and 1.3.6.x
        Hide
        Hudson added a comment -

        Integrated in ODE-trunk-jdk6 #419 (See https://builds.apache.org/job/ODE-trunk-jdk6/419/)
        fixing ODE-943: NoClassDefFoundError for org.apache.log4j.helpers.AbsoluteTimeDateFormat in SimpleScheduler.doLoadImmediate() leads memory leak

        From: Tammo van Lessen <vanto@apache.org> (Revision 1412351)

        Result = UNSTABLE
        vanto : http://svn.apache.org/viewvc/ode/trunk/?view=rev&rev=1412351
        Files :

        • /ode/trunk/scheduler-simple/src/main/java/org/apache/ode/scheduler/simple/SimpleScheduler.java
        Show
        Hudson added a comment - Integrated in ODE-trunk-jdk6 #419 (See https://builds.apache.org/job/ODE-trunk-jdk6/419/ ) fixing ODE-943 : NoClassDefFoundError for org.apache.log4j.helpers.AbsoluteTimeDateFormat in SimpleScheduler.doLoadImmediate() leads memory leak From: Tammo van Lessen <vanto@apache.org> (Revision 1412351) Result = UNSTABLE vanto : http://svn.apache.org/viewvc/ode/trunk/?view=rev&rev=1412351 Files : /ode/trunk/scheduler-simple/src/main/java/org/apache/ode/scheduler/simple/SimpleScheduler.java
        Hide
        Hudson added a comment -

        Integrated in ODE-1.x #138 (See https://builds.apache.org/job/ODE-1.x/138/)
        fixing ODE-943: NoClassDefFoundError for org.apache.log4j.helpers.AbsoluteTimeDateFormat in SimpleScheduler.doLoadImmediate() leads memory leak (Revision 1412353)

        Result = ABORTED
        vanto : http://svn.apache.org/viewvc/ode/trunk/?view=rev&rev=1412353
        Files :

        • /ode/branches/ode-1.3.6.x/scheduler-simple/src/main/java/org/apache/ode/scheduler/simple/SimpleScheduler.java
        Show
        Hudson added a comment - Integrated in ODE-1 .x #138 (See https://builds.apache.org/job/ODE-1.x/138/ ) fixing ODE-943 : NoClassDefFoundError for org.apache.log4j.helpers.AbsoluteTimeDateFormat in SimpleScheduler.doLoadImmediate() leads memory leak (Revision 1412353) Result = ABORTED vanto : http://svn.apache.org/viewvc/ode/trunk/?view=rev&rev=1412353 Files : /ode/branches/ode-1.3.6.x/scheduler-simple/src/main/java/org/apache/ode/scheduler/simple/SimpleScheduler.java
        Hide
        Mateusz Nowakowski added a comment -

        >The last comment is a new issue, shall I open a new one or do you, Mateusz want to do that? Do you have a patch handy already?

        Yes, please the workaround with setting configuration to huge values has been tested.
        I'll propose a patch for that soon.

        Show
        Mateusz Nowakowski added a comment - >The last comment is a new issue, shall I open a new one or do you, Mateusz want to do that? Do you have a patch handy already? Yes, please the workaround with setting configuration to huge values has been tested. I'll propose a patch for that soon.
        Hide
        Hudson added a comment -

        SUCCESS: Integrated in ODE-1.x #429 (See https://builds.apache.org/job/ODE-1.x/429/)
        Revert "ODE-943: fixing a scheduler bug. Thanks Waruna for the patch." (vanto: rev ffccd41af8fce424e4e914536a86ebcaeb4a2836)

        • scheduler-simple/src/main/java/org/apache/ode/scheduler/simple/SimpleScheduler.java
        Show
        Hudson added a comment - SUCCESS: Integrated in ODE-1 .x #429 (See https://builds.apache.org/job/ODE-1.x/429/ ) Revert " ODE-943 : fixing a scheduler bug. Thanks Waruna for the patch." (vanto: rev ffccd41af8fce424e4e914536a86ebcaeb4a2836) scheduler-simple/src/main/java/org/apache/ode/scheduler/simple/SimpleScheduler.java

          People

          • Assignee:
            Tammo van Lessen
            Reporter:
            Abdulkadir Yaman
          • Votes:
            1 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development