1 Reply Latest reply on Dec 19, 2011 1:22 PM by Matt Hernon

    SMX hangs when debug enabled- apache-servicemix-4.4.1-fuse-01-06

    Piotr Klimczak Newbie

      Hi,

       

      I have found a strange bug that hang SMX.

      It occurs only on fresh/clean SMX installation (where clean means data dir was deleted) when you edit the: org.ops4j.pax.logging.cfg file (before SMX start) and set the value of: log4j.rootLogger to: DEBUG, out, osgi:VmLogAppender.

       

      Once the file was changed, you will newer get the SMX to work.

      Not sure right now is it a FUSE ESB specific problem or SMX problem.

       

      Unfortunately i have no idea what causes the problem and unfortunately do not have time to investigate what is wrong.

       

      The log always stops at this point:

      17:06:02,397 | INFO  | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 | Installing bundle mvn:org.apache.camel/camel-blueprint/2.8.0-fuse-01-06

      17:06:02,401 | DEBUG | lixDispatchQueue | camel-blueprint                  | 145 - org.apache.camel.camel-blueprint - 2.8.0.fuse-01-06 | BundleEvent INSTALLED

      17:06:02,503 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 | Refeshing bundle org.ops4j.pax.logging.pax-logging-service (3) to solve the following optional imports

      17:06:02,503 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 |     javax.jms;resolution:=optional

      17:06:02,503 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 |     javax.mail;resolution:=optional

      17:06:02,504 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 |     javax.mail.internet;resolution:=optional

      17:06:02,510 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 | Refeshing bundle org.apache.karaf.shell.osgi (32) to solve the following optional imports

      17:06:02,510 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 |     org.springframework.osgi.context.event;resolution:=optional;version="[1.2,2)"

      17:06:02,510 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 |     org.springframework.osgi.extender.event;resolution:=optional;version="[1.2,2)"

      17:06:02,510 | DEBUG | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 |     org.springframework.osgi.service.importer.event;resolution:=optional;version="[1.2,2)"

      17:06:02,511 | INFO  | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 | Bundles to refresh: org.apache.karaf.shell.osgi (32), org.ops4j.pax.logging.pax-logging-service (3)

      17:06:02,511 | INFO  | Thread-6         | FeaturesServiceImpl              | 14 - org.apache.karaf.features.core - 2.2.2.fuse-02-06 | Refreshing bundles: org.apache.karaf.shell.osgi (32), org.ops4j.pax.logging.pax-logging-service (3)

      17:06:02,512 | DEBUG | elixPackageAdmin | BlueprintExtender                | 10 - org.apache.aries.blueprint - 0.3.1 | Destroying BlueprintContainer for bundle org.apache.karaf.shell.log

      17:06:02,512 | DEBUG | elixPackageAdmin | BlueprintEventDispatcher         | 10 - org.apache.aries.blueprint - 0.3.1 | Sending blueprint container event BlueprintEvent[type=DESTROYING] for bundle org.apache.karaf.shell.log

      17:06:02,512 | DEBUG | nt Dispatcher: 1 | BlueprintListener                | 32 - org.apache.karaf.shell.osgi - 2.2.2.fuse-02-06 | Blueprint app state changed to Destroying for bundle 22

      17:06:02,512 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,512 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service shell-42

      17:06:02,512 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,513 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,513 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service shell-46

      17:06:02,513 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,513 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,513 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service shell-48

      17:06:02,513 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,513 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,513 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service shell-40

      17:06:02,513 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,514 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,514 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service .component-1

      17:06:02,514 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,514 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,514 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service shell-44

      17:06:02,514 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,514 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,514 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Unregistering service shell-38

      17:06:02,514 | DEBUG | elixPackageAdmin | ServiceRecipe                    | 10 - org.apache.aries.blueprint - 0.3.1 | Calling listeners for service unregistration

      17:06:02,514 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,515 | DEBUG | elixPackageAdmin | CmPropertyPlaceholder            | 10 - org.apache.aries.blueprint - 0.3.1 | Destroying CmPropertyPlaceholder

      17:06:02,515 | DEBUG | elixPackageAdmin | log                              | 22 - org.apache.karaf.shell.log - 2.2.2.fuse-02-06 | ServiceEvent UNREGISTERING

      17:06:02,515 | DEBUG | elixPackageAdmin | BlueprintEventDispatcher         | 10 - org.apache.aries.blueprint - 0.3.1 | Sending blueprint container event BlueprintEvent[type=DESTROYED] for bundle org.apache.karaf.shell.log

      17:06:02,515 | DEBUG | nt Dispatcher: 1 | BlueprintListener                | 32 - org.apache.karaf.shell.osgi - 2.2.2.fuse-02-06 | Blueprint app state changed to Destroyed for bundle 22

      17:06:02,515 | DEBUG | elixPackageAdmin | BlueprintContainerImpl           | 10 - org.apache.aries.blueprint - 0.3.1 | Blueprint container destroyed: org.apache.felix.framework.BundleContextImpl@3dc98360

       

      I have also noticed that the java process takes 100 of cpu core usage.

      This problem occurs on both: sun-jdk and ibm-jdk

       

      Hope that would be helpful enough.

       

      Greetings,

      Piotr Klimczak