Uploaded image for project: 'OpenNMS'
  1. OpenNMS
  2. NMS-8946

Bundle bluepring-syslog-handler-default cannot be started and blocks Karaf container completly

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved (View Workflow)
    • Priority: Blocker
    • Resolution: Fixed
    • Affects Version/s: 19.0.0
    • Fix Version/s: 19.0.0
    • Component/s: OSGi
    • Security Level: Default (Default Security Scheme)
    • Labels:
      None

      Description

      In some circumstances it may occur, that the Karaf Container does not initialize completely.

      In that case the bundle "org.opennms.features.events.syslog.blueprint-syslog-handler-default" is starting and hangs in state "Creating".

      opennms> list | grep -i creating
      [ 148] [Active     ] [Creating    ] [       ] [   80] org.opennms.features.events.syslog.blueprint-syslog-handler-default (19.0.0.SNAPSHOT)
      

      The bundle is not continuing starting up and blocks the whole startup process of karaf.
      Looking at the karaf log, it seems, that the activemq broker is not started:

      2016-12-09 10:21:43,256 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 10 attempt(s) continuing to retry.
      2016-12-09 10:21:44,620 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 10 attempt(s) continuing to retry.
      2016-12-09 10:25:49,511 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 20 attempt(s) continuing to retry.
      2016-12-09 10:25:50,824 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 20 attempt(s) continuing to retry.
      2016-12-09 10:30:49,970 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 30 attempt(s) continuing to retry.
      2016-12-09 10:30:51,141 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 30 attempt(s) continuing to retry.
      2016-12-09 10:35:50,420 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 40 attempt(s) continuing to retry.
      2016-12-09 10:35:51,418 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 40 attempt(s) continuing to retry.
      2016-12-09 10:40:50,765 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 50 attempt(s) continuing to retry.
      2016-12-09 10:40:51,605 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 50 attempt(s) continuing to retry.
      2016-12-09 10:45:51,157 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 60 attempt(s) continuing to retry.
      2016-12-09 10:45:51,722 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 60 attempt(s) continuing to retry.
      2016-12-09 10:50:43,868 | INFO  | c]-nio2-thread-1 | ServerSession                    | 24 - org.apache.sshd.core - 0.14.0 | Server session created from /127.0.0.1:62686
      2016-12-09 10:50:44,758 | INFO  | c]-nio2-thread-5 | OpenNMSLoginModule               | 56 - org.opennms.container.jaas-login-module - 19.0.0.SNAPSHOT | OpenNMS Login Module initializing: subject=Subjekt:
      , callbackHandler=javax.security.auth.login.LoginContext$SecureCallbackHandler@2ca9b759, sharedState={}, options={org.osgi.framework.BundleContext=org.apache.felix.framework.BundleContextImpl@7050fd20}
      2016-12-09 10:50:44,762 | DEBUG | c]-nio2-thread-5 | OpenNMSLoginModule               | 56 - org.opennms.container.jaas-login-module - 19.0.0.SNAPSHOT | created principals from authority ROLE_ADMIN: [RolePrincipal[admin], RolePrincipal[ROLE_ADMIN], RolePrincipal[ADMIN]]
      2016-12-09 10:50:44,765 | DEBUG | c]-nio2-thread-5 | OpenNMSLoginModule               | 56 - org.opennms.container.jaas-login-module - 19.0.0.SNAPSHOT | created principals from authority ROLE_USER: [RolePrincipal[ROLE_USER], RolePrincipal[USER], RolePrincipal[user]]
      2016-12-09 10:50:44,770 | INFO  | c]-nio2-thread-5 | ServerUserAuthService            | 24 - org.apache.sshd.core - 0.14.0 | Session admin@/127.0.0.1:62686 authenticated
      2016-12-09 10:50:51,573 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 70 attempt(s) continuing to retry.
      2016-12-09 10:50:51,895 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 70 attempt(s) continuing to retry.
      2016-12-09 10:55:51,981 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 80 attempt(s) continuing to retry.
      2016-12-09 10:55:51,981 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 80 attempt(s) continuing to retry.
      2016-12-09 11:00:52,765 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 90 attempt(s) continuing to retry.
      2016-12-09 11:00:52,765 | WARN  | ActiveMQ Task-1  | FailoverTransport                | 122 - org.apache.activemq.activemq-osgi - 5.10.0 | Failed to connect to [tcp://localhost:61616] after: 90 attempt(s) continuing to retry.
      

      Looking in the eventd.log, this seems to true:

       3317 Caused by: javax.jms.JMSException: Could not create Transport. Reason: java.io.IOException: Broker named 'localhost' does not exist.
      

      I also set a breakpoint in the BrokerFactoryBean#afterPropertiesSet to see if the broker is initialized, but that method id never invoked.
      Looking again at the eventd.log it seems, that the `applicationContext-activemq.xml` is started AFTER the `applicationContext-common` which may cause the problem.

       3212 2016-12-07 13:45:55,890 INFO  [Main] o.s.c.s.ClassPathXmlApplicationContext: Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@7ae67ce1: startup date [Wed Dec 07 13:45:55 CET 2016]; parent: ApplicationContext 'commonContext'
       3213 2016-12-07 13:45:55,890 INFO  [Main] o.s.b.f.x.XmlBeanDefinitionReader: Loading XML bean definitions from class path resource [META-INF/opennms/applicationContext-daemon.xml]
       3214 2016-12-07 13:45:55,905 INFO  [Main] o.s.b.f.x.XmlBeanDefinitionReader: Loading XML bean definitions from class path resource [META-INF/opennms/applicationContext-pinger.xml]
       3215 2016-12-07 13:45:55,953 INFO  [Main] o.s.b.f.x.XmlBeanDefinitionReader: Loading XML bean definitions from class path resource [META-INF/opennms/applicationContext-activemq.xml]
      

      We should make sure, that the broker is always initialized first.

      Because starting bundle blocks karaf completely. It is not possible to start/stop/uninstall that bundle. Stopping OpenNMS is also not possible.
      We should make sure, that bundles do not block the startup of karaf if the broker is not available (yet).

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                j-white Jesse White
                Reporter:
                mvr Markus von RĂ¼den
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: