[ODLPARENT-82] Restconf does not start in Karaf 4 Created: 30/Mar/17  Updated: 24/Jan/18  Resolved: 10/Apr/17

Status: Resolved
Project: odlparent
Component/s: General
Affects Version/s: None
Fix Version/s: None

Type: Bug
Reporter: Vratko Polak Assignee: Robert Varga
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All


Issue Links:
Blocks
blocks ODLPARENT-23 Milestone: Upgrade karaf to 4.0.1 or ... Resolved
External issue ID: 8117

 Description   

This blocks Karaf 4 work on jobs related to distribution, for example all csit jobs.

Issuing "feature:install odl-restconf" succeeds, but subsequent Restconf queries do not work.
More specifically, HTTP connection stays open for a few minutes, and then ODL closes the connection.

Possible causes are described in e-mail [2].

[2] https://lists.opendaylight.org/pipermail/odlparent-dev/2017-March/000895.html



 Comments   
Comment by Vratko Polak [ 30/Mar/17 ]

opendaylight-user@root>bundle:list | grep -v Active
START LEVEL 100 , List Threshold: 50
ID | State | Lvl | Version | Name
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
192 | Resolved | 80 | 0.6.0.SNAPSHOT | config-persister-directory-xml-adapter, Hosts: 194
193 | Resolved | 80 | 0.6.0.SNAPSHOT | config-persister-file-xml-adapter, Hosts: 194

Comment by Vratko Polak [ 30/Mar/17 ]

First warning in karaf.log:

2017-03-30 17:37:05,772 | WARN | ender-2-thread-1 | JettyServerWrapper | 292 - org.ops4j.pax.web.pax-web-jetty - 4.3.0 | Failed to find annotated classes for ServletContainerInitializer
java.lang.RuntimeException
at org.objectweb.asm.MethodVisitor.visitParameter(Unknown Source)[166:org.objectweb.asm:5.0.3]
at org.objectweb.asm.ClassReader.b(Unknown Source)[166:org.objectweb.asm:5.0.3]
at org.objectweb.asm.ClassReader.accept(Unknown Source)[166:org.objectweb.asm:5.0.3]
at org.objectweb.asm.ClassReader.accept(Unknown Source)[166:org.objectweb.asm:5.0.3]
at org.apache.xbean.finder.AbstractFinder.readClassDef(AbstractFinder.java:581)[132:org.apache.xbean.finder:4.1.0]
at org.apache.xbean.finder.BundleAnnotationFinder$AnnotationFindingCallback.foundInDirectory(BundleAnnotationFinder.java:86)[132:org.apache.xbean.finder:4.1.0]
at org.apache.xbean.osgi.bundle.util.BundleResourceFinder.scanDirectory(BundleResourceFinder.java:151)[131:org.apache.xbean.bundleutils:4.1.0]
at org.apache.xbean.osgi.bundle.util.BundleResourceFinder.scanBundleClassPath(BundleResourceFinder.java:120)[131:org.apache.xbean.bundleutils:4.1.0]
at org.apache.xbean.osgi.bundle.util.BundleResourceFinder.find(BundleResourceFinder.java:88)[131:org.apache.xbean.bundleutils:4.1.0]
at org.apache.xbean.finder.BundleAnnotationFinder.<init>(BundleAnnotationFinder.java:56)[132:org.apache.xbean.finder:4.1.0]
at org.apache.xbean.finder.BundleAnnotationFinder.<init>(BundleAnnotationFinder.java:50)[132:org.apache.xbean.finder:4.1.0]
at org.apache.xbean.finder.BundleAnnotationFinder.<init>(BundleAnnotationFinder.java:46)[132:org.apache.xbean.finder:4.1.0]
at org.ops4j.pax.web.service.jetty.internal.JettyServerWrapper.addContext(JettyServerWrapper.java:352)[292:org.ops4j.pax.web.pax-web-jetty:4.3.0]
at org.ops4j.pax.web.service.jetty.internal.JettyServerWrapper.getOrCreateContext(JettyServerWrapper.java:219)[292:org.ops4j.pax.web.pax-web-jetty:4.3.0]
at org.ops4j.pax.web.service.jetty.internal.JettyServerImpl.getContext(JettyServerImpl.java:267)[292:org.ops4j.pax.web.pax-web-jetty:4.3.0]
at org.ops4j.pax.web.service.jetty.internal.ServerControllerImpl$Started.getContext(ServerControllerImpl.java:347)[292:org.ops4j.pax.web.pax-web-jetty:4.3.0]
at org.ops4j.pax.web.service.jetty.internal.ServerControllerImpl.getContext(ServerControllerImpl.java:176)[292:org.ops4j.pax.web.pax-web-jetty:4.3.0]
at org.ops4j.pax.web.service.internal.HttpServiceStarted.begin(HttpServiceStarted.java:1079)[294:org.ops4j.pax.web.pax-web-runtime:4.3.0]
at org.ops4j.pax.web.service.internal.HttpServiceProxy.begin(HttpServiceProxy.java:412)[294:org.ops4j.pax.web.pax-web-runtime:4.3.0]
at org.ops4j.pax.web.extender.war.internal.RegisterWebAppVisitorWC.visit(RegisterWebAppVisitorWC.java:176)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.model.WebApp.accept(WebApp.java:655)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.register(WebAppPublisher.java:237)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.addingService(WebAppPublisher.java:182)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.addingService(WebAppPublisher.java:135)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)[org.osgi.core-6.0.0.jar:]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher.publish(WebAppPublisher.java:101)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebObserver.deploy(WebObserver.java:219)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebObserver$1.doStart(WebObserver.java:179)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.extender.SimpleExtension.start(SimpleExtension.java:59)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.extender.AbstractExtender$1.run(AbstractExtender.java:281)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]

Comment by Vratko Polak [ 30/Mar/17 ]

This looks worse:

2017-03-30 17:37:07,692 | WARN | ender-2-thread-1 | AbstractLifeCycle | 148 - org.eclipse.jetty.util - 9.2.19.v20160908 | FAILED org.ops4j.pax.web.service.jetty.internal.JettyServerWrapper@192dae03: java.net.BindException: Address already in use
java.net.BindException: Address already in use
at sun.nio.ch.Net.bind0(Native Method)[:1.8.0_121]
at sun.nio.ch.Net.bind(Net.java:433)[:1.8.0_121]
at sun.nio.ch.Net.bind(Net.java:425)[:1.8.0_121]
at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)[:1.8.0_121]
at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)[:1.8.0_121]
at org.eclipse.jetty.server.ServerConnector.open(ServerConnector.java:321)[145:org.eclipse.jetty.server:9.2.19.v20160908]
at org.eclipse.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)[145:org.eclipse.jetty.server:9.2.19.v20160908]
at org.eclipse.jetty.server.ServerConnector.doStart(ServerConnector.java:236)[145:org.eclipse.jetty.server:9.2.19.v20160908]
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)[148:org.eclipse.jetty.util:9.2.19.v20160908]
at org.eclipse.jetty.server.Server.doStart(Server.java:366)[145:org.eclipse.jetty.server:9.2.19.v20160908]
at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)[148:org.eclipse.jetty.util:9.2.19.v20160908]
at org.ops4j.pax.web.service.jetty.internal.JettyServerImpl$1.start(JettyServerImpl.java:287)[292:org.ops4j.pax.web.pax-web-jetty:4.3.0]
at org.ops4j.pax.web.service.internal.HttpServiceStarted.end(HttpServiceStarted.java:1096)[294:org.ops4j.pax.web.pax-web-runtime:4.3.0]
at org.ops4j.pax.web.service.internal.HttpServiceProxy.end(HttpServiceProxy.java:417)[294:org.ops4j.pax.web.pax-web-runtime:4.3.0]
at org.ops4j.pax.web.extender.war.internal.RegisterWebAppVisitorWC.end(RegisterWebAppVisitorWC.java:380)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.model.WebApp.accept(WebApp.java:692)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.register(WebAppPublisher.java:237)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.addingService(WebAppPublisher.java:182)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.addingService(WebAppPublisher.java:135)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)[org.osgi.core-6.0.0.jar:]
at org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)[org.osgi.core-6.0.0.jar:]
at org.ops4j.pax.web.extender.war.internal.WebAppPublisher.publish(WebAppPublisher.java:101)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebObserver.deploy(WebObserver.java:219)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.WebObserver$1.doStart(WebObserver.java:179)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.extender.SimpleExtension.start(SimpleExtension.java:59)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at org.ops4j.pax.web.extender.war.internal.extender.AbstractExtender$1.run(AbstractExtender.java:281)[290:org.ops4j.pax.web.pax-web-extender-war:4.3.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]

Comment by Tomas Cere [ 31/Mar/17 ]

Not only restconf related, this is present in the logs even when any other feature is installed(i observed this with odl-netconf-topology) seems like jetty has some issues.

Comment by Robert Varga [ 10/Apr/17 ]

The problem seems be coming from pax-web's integration of jetty, more specifically the code invoked around https://github.com/ops4j/org.ops4j.pax.web/blob/pax-web-4.3.x/pax-web-jetty/src/main/java/org/ops4j/pax/web/service/jetty/internal/ServerControllerImpl.java#L422

I think the culprit is that our jetty.xml does not declare the port number, but only specifies the default (or something similar), leading to https://github.com/ops4j/org.ops4j.pax.web/blob/pax-web-4.3.x/pax-web-jetty/src/main/java/org/ops4j/pax/web/service/jetty/internal/ServerControllerImpl.java#L580 failing the compare, which triggers the code path https://github.com/ops4j/org.ops4j.pax.web/blob/pax-web-4.3.x/pax-web-jetty/src/main/java/org/ops4j/pax/web/service/jetty/internal/ServerControllerImpl.java#L461

My theory is that this causes two connectors to be configured on the same port, leading the the failure.

Comment by Robert Varga [ 10/Apr/17 ]

master: https://git.opendaylight.org/gerrit/54611

Generated at Wed Feb 07 20:27:34 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.