You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@karaf.apache.org by Michael Täschner <m....@gmail.com> on 2016/02/22 11:37:41 UTC
JMX SSL issue - Unable to lookup configured keystore and/or truststore
Hi karaf-Users,
we have a sporadic issue with Karaf initialization of JMX
ConnectorServerFactory due to "Unable to lookup configured keystore and/or
truststore" (see stacktrace below [1]). The ConnectorServerFactory uses
JAAS keystore for configuration of encrypted SSL for JMX via blueprint
config and fileInstall for initialization of the keystore.xml at specific
startlevel. In about 1 of 10 restarts (using "clean" for full
initialization), the keys are not loaded into the keystore and the
MBeanServer is not initialized correctly. This seems to be due to the fact
that on "init()" of ConnectorServerFactory bean the setupSSL() is called
and tries to retrieve the keystore from the OsgiKeystoreManager. This call
does not wait for the keystore to be registered so if due to timing issues
the jaas keystore not having been loaded yet the method fails immediately
with the exception [1] leaving the container in an unusable state. Is there
as possibility for the ConnectorServerFactory to wait on the keystore being
available at the keystoreManager and delay initialization?
Current startlevels do not allow for much leeway regarding loading the jaas
keystore:
- level 24 - initialization of the "blueprint" wrapper
- level 25 - recommended startlevel in felix fileinstall for loading
keystore.xml
- level 30 - initialization of karaf-management component
[1]
[2016-02-18 09:48:03,623] [ERROR] [FelixStartLevel]
[o.a.a.b.c.BlueprintContainerImpl] 403 | [] [21 -
org.apache.aries.blueprint.core - 1.4.2] [] [] [] [] [] [] Unable to start
blueprint container for bundl
e org.apache.karaf.management.server
org.osgi.service.blueprint.container.ComponentDefinitionException: Unable
to initialize bean connectorFactory
at
org.apache.aries.blueprint.container.BeanRecipe.runBeanProcInit(BeanRecipe.java:714)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:824)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:787)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:79)
[org.apache.aries.blueprint.core:1.4.2]
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[na:1.7.0_51]
at
org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:88)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:245)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:183)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:682)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:377)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:269)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:294)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:263)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:253)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500)
[org.apache.aries.util:1.1.0]
at
org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433)
[org.apache.aries.util:1.1.0]
at
org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725)
[org.apache.aries.util:1.1.0]
at
org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463)
[org.apache.aries.util:1.1.0]
at
org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422)
[org.apache.aries.util:1.1.0]
at
org.apache.felix.framework.util.SecureAction.invokeBundleEventHook(SecureAction.java:1127)
[org.apache.felix.framework-4.4.1.jar:na]
at
org.apache.felix.framework.util.EventDispatcher.createWhitelistFromHooks(EventDispatcher.java:696)
[org.apache.felix.framework-4.4.1.jar:na]
at
org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:484)
[org.apache.felix.framework-4.4.1.jar:na]
at
org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4429)
[org.apache.felix.framework-4.4.1.jar:na]
at org.apache.felix.framework.Felix.startBundle(Felix.java:2100)
[org.apache.felix.framework-4.4.1.jar:na]
at
org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1299)
[org.apache.felix.framework-4.4.1.jar:na]
at
org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:304)
[org.apache.felix.framework-4.4.1.jar:na]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
Caused by: java.security.GeneralSecurityException: Unable to lookup
configured keystore and/or truststore
at
org.apache.karaf.jaas.config.impl.OsgiKeystoreManager.createSSLContext(OsgiKeystoreManager.java:70)
[na:na]
at
org.apache.karaf.jaas.config.impl.OsgiKeystoreManager.createSSLServerFactory(OsgiKeystoreManager.java:100)
[na:na]
at
Proxy28fdb3db_ffe5_42c8_9b3e_26c55cec0cfc.createSSLServerFactory(Unknown
Source) [na:na]
at
org.apache.karaf.management.ConnectorServerFactory.setupSsl(ConnectorServerFactory.java:285)
[na:na]
at
org.apache.karaf.management.ConnectorServerFactory.init(ConnectorServerFactory.java:217)
[na:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[na:1.7.0_51]
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[na:1.7.0_51]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[na:1.7.0_51]
at java.lang.reflect.Method.invoke(Method.java:606) [na:1.7.0_51]
at
org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:297)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:958)
[org.apache.aries.blueprint.core:1.4.2]
at
org.apache.aries.blueprint.container.BeanRecipe.runBeanProcInit(BeanRecipe.java:712)
[org.apache.aries.blueprint.core:1.4.2]
... 26 common frames omitted
Thanks and Best Regards,
Michael
input for analysis:
[2] Fuse Remote JMX SSL guide:
https://access.redhat.com/documentation/en-US/Red_Hat_JBoss_Fuse/6.0/html/Security_Guide/files/ESBSecurityJmxSSL.html
[3] Karaf Security Framework guide:
http://karaf.apache.org/manual/latest-3.0.x/developers-guide/security-framework.html
[4] Previous Karaf-User Question regarding jaas:
http://karaf.922171.n3.nabble.com/JAAS-SSL-Issue-LDAPLoginModule-setupSsl-calls-OsgiKeystoreManager-createSSLFactory-with-timestamp-of0-td4026149.html
[5] ConnectorServerFactory source:
http://grepcode.com/file/repo1.maven.org/maven2/org.apache.karaf.management/org.apache.karaf.management.server/3.0.4/org/apache/karaf/management/ConnectorServerFactory.java#ConnectorServerFactory.init%28%29
Re: JMX SSL issue - Unable to lookup configured keystore and/or truststore
Posted by Michael Täschner <m....@gmail.com>.
Hi again,
some additional findings:
- the ConnectorServerFactory seems to get initialized first from the
default configuration provided inside
/OSGI-INF/blueprint/karaf-management.xml (from
org.apache.karaf.management.server bundle) but on re-initialize from
configuration file (etc/org.apache.karaf.management.cfg) it infrequently
fails because previous factory is not shut-down completely: "Can't re-init
JMXConnectorServer with SSL enabled when register a
keystore:connector:name=rmi"
- overriding config.properties "org.apache.aries.blueprint.synchronous"
with "true" prevents the blocking issue described in previous mail where
ConnectorServerFactory cannot find KeystoreInstance service because this is
initialized later
All in all these combination of behavior make it very difficult to set up a
reliant JMXRMI over SSL endpoint
Best Regards,
Michael
2016-07-19 15:26 GMT+02:00 Michael Täschner <m....@gmail.com>:
> Hi Karaf Users,
>
> my woes with the JMXRMI over SSL configuration using ServiceMix
> 6.1.1/Karaf 3.0.6 just became more serious. There seem to be some major
> start-up/timing issues involved and the secured JMXRMI endpoint does not
> get initalizied reliably.
>
> I used a default ServiceMix / Karaf container for reproducing the issues
> while ensuring our custom configuration does not cause the problems. Here
> are my findings (I used the configuration as described in KARAF-3887 [1])
>
> This is output karaf.log:
> 2016-07-19 15:10:02,927 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:03,927 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:04,928 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:04,929 | ERROR | FelixStartLevel |
> ConnectorServerFactory | 40 - org.apache.karaf.management.server
> - 3.0.6 | Can't init JMXConnectorServer with SSL enabled: Unable to lookup
> configured keystore and/or truststore
> 2016-07-19 15:10:04,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:05,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:06,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:07,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:08,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:09,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:10,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:11,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:12,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:13,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:14,938 | INFO | FelixStartLevel | OsgiKeystoreManager
> | 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
> karaf.keystore not found
> 2016-07-19 15:10:14,938 | ERROR | FelixStartLevel |
> ConnectorServerFactory | 40 - org.apache.karaf.management.server
> - 3.0.6 | Can't init JMXConnectorServer with SSL enabled: Unable to lookup
> configured keystore and/or truststore
>
> This looks like the KeystoreInstance Service registration and lookup by
> the OsgKeystoreManager are done in the same thread ?? After the configured
> "keyStoreAvailabilityTimeout" the second ERROR output is logged and
> initialization is aborted. Increasing the keyStoreAvailabilityTimeout just
> extends the trials and "Keystore karaf.keystore not found" logs seen before.
>
> To check if the timing is relevant I set "featuresBootAsynchronous" to
> "true" which lead to the following result:
>
> output karaf.log:
> 2016-07-19 11:45:03,698 | ERROR | FelixStartLevel |
> ConnectorServerFactory | 39 - org.apache.karaf.management.server
> - 3.0.6 | Can't re-init JMXConnectorServer with SSL enabled when register a
> keystore:connector:name=rmi
>
> Unfortunately the exception is not logged, but debugging into
> ConnectorServerFactory, the following exception is raised:
> javax.management.InstanceAlreadyExistsException: connector:name=rmi
>
> This is rather confusing as I can see no other JMXRMI endpoint provided by
> looking with JConsole/VisualVM ??
>
> As a result in both cases there is no JMXRMI endpoint created by the
> container??
>
> Any suggestions how to get around this ??
>
> [1] https://issues.apache.org/jira/browse/KARAF-3887
>
> 2016-02-22 11:37 GMT+01:00 Michael Täschner <m....@gmail.com>:
>
>> Hi karaf-Users,
>>
>> we have a sporadic issue with Karaf initialization of JMX
>> ConnectorServerFactory due to "Unable to lookup configured keystore and/or
>> truststore" (see stacktrace below [1]). The ConnectorServerFactory uses
>> JAAS keystore for configuration of encrypted SSL for JMX via blueprint
>> config and fileInstall for initialization of the keystore.xml at specific
>> startlevel. In about 1 of 10 restarts (using "clean" for full
>> initialization), the keys are not loaded into the keystore and the
>> MBeanServer is not initialized correctly. This seems to be due to the fact
>> that on "init()" of ConnectorServerFactory bean the setupSSL() is called
>> and tries to retrieve the keystore from the OsgiKeystoreManager. This call
>> does not wait for the keystore to be registered so if due to timing issues
>> the jaas keystore not having been loaded yet the method fails immediately
>> with the exception [1] leaving the container in an unusable state. Is there
>> as possibility for the ConnectorServerFactory to wait on the keystore being
>> available at the keystoreManager and delay initialization?
>>
>> Current startlevels do not allow for much leeway regarding loading the
>> jaas keystore:
>> - level 24 - initialization of the "blueprint" wrapper
>> - level 25 - recommended startlevel in felix fileinstall for loading
>> keystore.xml
>> - level 30 - initialization of karaf-management component
>>
>> [1]
>> [2016-02-18 09:48:03,623] [ERROR] [FelixStartLevel]
>> [o.a.a.b.c.BlueprintContainerImpl] 403 | [] [21 -
>> org.apache.aries.blueprint.core - 1.4.2] [] [] [] [] [] [] Unable to start
>> blueprint container for bundl
>> e org.apache.karaf.management.server
>> org.osgi.service.blueprint.container.ComponentDefinitionException: Unable
>> to initialize bean connectorFactory
>> at
>> org.apache.aries.blueprint.container.BeanRecipe.runBeanProcInit(BeanRecipe.java:714)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:824)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:787)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:79)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
>> [na:1.7.0_51]
>> at
>> org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:88)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:245)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:183)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:682)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:377)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:269)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:294)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:263)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:253)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500)
>> [org.apache.aries.util:1.1.0]
>> at
>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433)
>> [org.apache.aries.util:1.1.0]
>> at
>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725)
>> [org.apache.aries.util:1.1.0]
>> at
>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463)
>> [org.apache.aries.util:1.1.0]
>> at
>> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422)
>> [org.apache.aries.util:1.1.0]
>> at
>> org.apache.felix.framework.util.SecureAction.invokeBundleEventHook(SecureAction.java:1127)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at
>> org.apache.felix.framework.util.EventDispatcher.createWhitelistFromHooks(EventDispatcher.java:696)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at
>> org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:484)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at
>> org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4429)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at org.apache.felix.framework.Felix.startBundle(Felix.java:2100)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at
>> org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1299)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at
>> org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:304)
>> [org.apache.felix.framework-4.4.1.jar:na]
>> at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
>> Caused by: java.security.GeneralSecurityException: Unable to lookup
>> configured keystore and/or truststore
>> at
>> org.apache.karaf.jaas.config.impl.OsgiKeystoreManager.createSSLContext(OsgiKeystoreManager.java:70)
>> [na:na]
>> at
>> org.apache.karaf.jaas.config.impl.OsgiKeystoreManager.createSSLServerFactory(OsgiKeystoreManager.java:100)
>> [na:na]
>> at
>> Proxy28fdb3db_ffe5_42c8_9b3e_26c55cec0cfc.createSSLServerFactory(Unknown
>> Source) [na:na]
>> at
>> org.apache.karaf.management.ConnectorServerFactory.setupSsl(ConnectorServerFactory.java:285)
>> [na:na]
>> at
>> org.apache.karaf.management.ConnectorServerFactory.init(ConnectorServerFactory.java:217)
>> [na:na]
>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>> [na:1.7.0_51]
>> at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>> [na:1.7.0_51]
>> at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>> [na:1.7.0_51]
>> at java.lang.reflect.Method.invoke(Method.java:606) [na:1.7.0_51]
>> at
>> org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:297)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:958)
>> [org.apache.aries.blueprint.core:1.4.2]
>> at
>> org.apache.aries.blueprint.container.BeanRecipe.runBeanProcInit(BeanRecipe.java:712)
>> [org.apache.aries.blueprint.core:1.4.2]
>> ... 26 common frames omitted
>>
>> Thanks and Best Regards,
>> Michael
>>
>> input for analysis:
>> [2] Fuse Remote JMX SSL guide:
>> https://access.redhat.com/documentation/en-US/Red_Hat_JBoss_Fuse/6.0/html/Security_Guide/files/ESBSecurityJmxSSL.html
>> [3] Karaf Security Framework guide:
>> http://karaf.apache.org/manual/latest-3.0.x/developers-guide/security-framework.html
>> [4] Previous Karaf-User Question regarding jaas:
>> http://karaf.922171.n3.nabble.com/JAAS-SSL-Issue-LDAPLoginModule-setupSsl-calls-OsgiKeystoreManager-createSSLFactory-with-timestamp-of0-td4026149.html
>> [5] ConnectorServerFactory source:
>> http://grepcode.com/file/repo1.maven.org/maven2/org.apache.karaf.management/org.apache.karaf.management.server/3.0.4/org/apache/karaf/management/ConnectorServerFactory.java#ConnectorServerFactory.init%28%29
>>
>
>
Re: JMX SSL issue - Unable to lookup configured keystore and/or truststore
Posted by Michael Täschner <m....@gmail.com>.
Hi Karaf Users,
my woes with the JMXRMI over SSL configuration using ServiceMix 6.1.1/Karaf
3.0.6 just became more serious. There seem to be some major start-up/timing
issues involved and the secured JMXRMI endpoint does not get initalizied
reliably.
I used a default ServiceMix / Karaf container for reproducing the issues
while ensuring our custom configuration does not cause the problems. Here
are my findings (I used the configuration as described in KARAF-3887 [1])
This is output karaf.log:
2016-07-19 15:10:02,927 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:03,927 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:04,928 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:04,929 | ERROR | FelixStartLevel | ConnectorServerFactory
| 40 - org.apache.karaf.management.server - 3.0.6 | Can't init
JMXConnectorServer with SSL enabled: Unable to lookup configured keystore
and/or truststore
2016-07-19 15:10:04,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:05,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:06,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:07,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:08,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:09,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:10,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:11,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:12,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:13,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:14,938 | INFO | FelixStartLevel | OsgiKeystoreManager
| 29 - org.apache.karaf.jaas.config - 3.0.6 | Keystore
karaf.keystore not found
2016-07-19 15:10:14,938 | ERROR | FelixStartLevel | ConnectorServerFactory
| 40 - org.apache.karaf.management.server - 3.0.6 | Can't init
JMXConnectorServer with SSL enabled: Unable to lookup configured keystore
and/or truststore
This looks like the KeystoreInstance Service registration and lookup by the
OsgKeystoreManager are done in the same thread ?? After the configured
"keyStoreAvailabilityTimeout" the second ERROR output is logged and
initialization is aborted. Increasing the keyStoreAvailabilityTimeout just
extends the trials and "Keystore karaf.keystore not found" logs seen before.
To check if the timing is relevant I set "featuresBootAsynchronous" to
"true" which lead to the following result:
output karaf.log:
2016-07-19 11:45:03,698 | ERROR | FelixStartLevel | ConnectorServerFactory
| 39 - org.apache.karaf.management.server - 3.0.6 | Can't re-init
JMXConnectorServer with SSL enabled when register a
keystore:connector:name=rmi
Unfortunately the exception is not logged, but debugging into
ConnectorServerFactory, the following exception is raised:
javax.management.InstanceAlreadyExistsException: connector:name=rmi
This is rather confusing as I can see no other JMXRMI endpoint provided by
looking with JConsole/VisualVM ??
As a result in both cases there is no JMXRMI endpoint created by the
container??
Any suggestions how to get around this ??
[1] https://issues.apache.org/jira/browse/KARAF-3887
2016-02-22 11:37 GMT+01:00 Michael Täschner <m....@gmail.com>:
> Hi karaf-Users,
>
> we have a sporadic issue with Karaf initialization of JMX
> ConnectorServerFactory due to "Unable to lookup configured keystore and/or
> truststore" (see stacktrace below [1]). The ConnectorServerFactory uses
> JAAS keystore for configuration of encrypted SSL for JMX via blueprint
> config and fileInstall for initialization of the keystore.xml at specific
> startlevel. In about 1 of 10 restarts (using "clean" for full
> initialization), the keys are not loaded into the keystore and the
> MBeanServer is not initialized correctly. This seems to be due to the fact
> that on "init()" of ConnectorServerFactory bean the setupSSL() is called
> and tries to retrieve the keystore from the OsgiKeystoreManager. This call
> does not wait for the keystore to be registered so if due to timing issues
> the jaas keystore not having been loaded yet the method fails immediately
> with the exception [1] leaving the container in an unusable state. Is there
> as possibility for the ConnectorServerFactory to wait on the keystore being
> available at the keystoreManager and delay initialization?
>
> Current startlevels do not allow for much leeway regarding loading the
> jaas keystore:
> - level 24 - initialization of the "blueprint" wrapper
> - level 25 - recommended startlevel in felix fileinstall for loading
> keystore.xml
> - level 30 - initialization of karaf-management component
>
> [1]
> [2016-02-18 09:48:03,623] [ERROR] [FelixStartLevel]
> [o.a.a.b.c.BlueprintContainerImpl] 403 | [] [21 -
> org.apache.aries.blueprint.core - 1.4.2] [] [] [] [] [] [] Unable to start
> blueprint container for bundl
> e org.apache.karaf.management.server
> org.osgi.service.blueprint.container.ComponentDefinitionException: Unable
> to initialize bean connectorFactory
> at
> org.apache.aries.blueprint.container.BeanRecipe.runBeanProcInit(BeanRecipe.java:714)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:824)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:787)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:79)
> [org.apache.aries.blueprint.core:1.4.2]
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> [na:1.7.0_51]
> at
> org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:88)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:245)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:183)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:682)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:377)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:269)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:294)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintExtender.createContainer(BlueprintExtender.java:263)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BlueprintExtender.modifiedBundle(BlueprintExtender.java:253)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:500)
> [org.apache.aries.util:1.1.0]
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.customizerModified(BundleHookBundleTracker.java:433)
> [org.apache.aries.util:1.1.0]
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$AbstractTracked.track(BundleHookBundleTracker.java:725)
> [org.apache.aries.util:1.1.0]
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$Tracked.bundleChanged(BundleHookBundleTracker.java:463)
> [org.apache.aries.util:1.1.0]
> at
> org.apache.aries.util.tracker.hook.BundleHookBundleTracker$BundleEventHook.event(BundleHookBundleTracker.java:422)
> [org.apache.aries.util:1.1.0]
> at
> org.apache.felix.framework.util.SecureAction.invokeBundleEventHook(SecureAction.java:1127)
> [org.apache.felix.framework-4.4.1.jar:na]
> at
> org.apache.felix.framework.util.EventDispatcher.createWhitelistFromHooks(EventDispatcher.java:696)
> [org.apache.felix.framework-4.4.1.jar:na]
> at
> org.apache.felix.framework.util.EventDispatcher.fireBundleEvent(EventDispatcher.java:484)
> [org.apache.felix.framework-4.4.1.jar:na]
> at
> org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4429)
> [org.apache.felix.framework-4.4.1.jar:na]
> at org.apache.felix.framework.Felix.startBundle(Felix.java:2100)
> [org.apache.felix.framework-4.4.1.jar:na]
> at
> org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1299)
> [org.apache.felix.framework-4.4.1.jar:na]
> at
> org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:304)
> [org.apache.felix.framework-4.4.1.jar:na]
> at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]
> Caused by: java.security.GeneralSecurityException: Unable to lookup
> configured keystore and/or truststore
> at
> org.apache.karaf.jaas.config.impl.OsgiKeystoreManager.createSSLContext(OsgiKeystoreManager.java:70)
> [na:na]
> at
> org.apache.karaf.jaas.config.impl.OsgiKeystoreManager.createSSLServerFactory(OsgiKeystoreManager.java:100)
> [na:na]
> at
> Proxy28fdb3db_ffe5_42c8_9b3e_26c55cec0cfc.createSSLServerFactory(Unknown
> Source) [na:na]
> at
> org.apache.karaf.management.ConnectorServerFactory.setupSsl(ConnectorServerFactory.java:285)
> [na:na]
> at
> org.apache.karaf.management.ConnectorServerFactory.init(ConnectorServerFactory.java:217)
> [na:na]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> [na:1.7.0_51]
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> [na:1.7.0_51]
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> [na:1.7.0_51]
> at java.lang.reflect.Method.invoke(Method.java:606) [na:1.7.0_51]
> at
> org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:297)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:958)
> [org.apache.aries.blueprint.core:1.4.2]
> at
> org.apache.aries.blueprint.container.BeanRecipe.runBeanProcInit(BeanRecipe.java:712)
> [org.apache.aries.blueprint.core:1.4.2]
> ... 26 common frames omitted
>
> Thanks and Best Regards,
> Michael
>
> input for analysis:
> [2] Fuse Remote JMX SSL guide:
> https://access.redhat.com/documentation/en-US/Red_Hat_JBoss_Fuse/6.0/html/Security_Guide/files/ESBSecurityJmxSSL.html
> [3] Karaf Security Framework guide:
> http://karaf.apache.org/manual/latest-3.0.x/developers-guide/security-framework.html
> [4] Previous Karaf-User Question regarding jaas:
> http://karaf.922171.n3.nabble.com/JAAS-SSL-Issue-LDAPLoginModule-setupSsl-calls-OsgiKeystoreManager-createSSLFactory-with-timestamp-of0-td4026149.html
> [5] ConnectorServerFactory source:
> http://grepcode.com/file/repo1.maven.org/maven2/org.apache.karaf.management/org.apache.karaf.management.server/3.0.4/org/apache/karaf/management/ConnectorServerFactory.java#ConnectorServerFactory.init%28%29
>
Re: JMX SSL issue - Unable to lookup configured keystore and/or
truststore
Posted by rsteppac2 <ra...@steppacher.name>.
We have the same problem with 4.0.7. Is there a JIRA ticket to track the
issue? I found https://issues.apache.org/jira/browse/KARAF-3887 but I don't
think it is the same issue.
Thanks
Ralf
--
View this message in context: http://karaf.922171.n3.nabble.com/JMX-SSL-issue-Unable-to-lookup-configured-keystore-and-or-truststore-tp4045492p4049533.html
Sent from the Karaf - User mailing list archive at Nabble.com.
Re: JMX SSL issue - Unable to lookup configured keystore and/or
truststore
Posted by SvS <Du...@solcon.nl>.
Also a problem in karaf version 4.0.4 and 4.0.6. Is there a solution or
workaround?
--
View this message in context: http://karaf.922171.n3.nabble.com/JMX-SSL-issue-Unable-to-lookup-configured-keystore-and-or-truststore-tp4045492p4047907.html
Sent from the Karaf - User mailing list archive at Nabble.com.
Re: JMX SSL issue - Unable to lookup configured keystore and/or
truststore
Posted by SvS <Du...@solcon.nl>.
Any update?
--
View this message in context: http://karaf.922171.n3.nabble.com/JMX-SSL-issue-Unable-to-lookup-configured-keystore-and-or-truststore-tp4045492p4047906.html
Sent from the Karaf - User mailing list archive at Nabble.com.