SMX hangs when debug enabled- apache-servicemix-4.4.1-fuse-01-06
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
