[NETCONF-591] Netconf connection failing in master (neon) Created: 08/Jan/19  Updated: 24/Jan/19  Resolved: 23/Jan/19

Status: Resolved
Project: netconf
Component/s: None
Affects Version/s: Neon
Fix Version/s: Neon

Type: Bug Priority: High
Reporter: Luis Gomez Assignee: Luis Gomez
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Blocks
is blocked by YANGTOOLS-926 XMLStreamNormalizedNodeStreamWriter a... Resolved
Relates
relates to CONTROLLER-1867 Cluster: Member fail to start with od... Resolved

 Description   

Netconf basic CSIT is failing:
https://jenkins.opendaylight.org/releng/view/netconf/job/netconf-csit-1node-userfeatures-all-neon

Looking at the karaf log we can see:

Caused by: org.w3c.dom.DOMException: NAMESPACE_ERR: An attempt is made to create or change an object in a way which is incorrect with regard to namespaces.

Which means we will need to repair and merge this patch already merged in fluorine:

https://git.opendaylight.org/gerrit/#/c/77471

 Comments   
Comment by Robert Varga [ 12/Jan/19 ]

Neon shading needs to be expanded to make grammar-informed encoding work, which is done by the original patch. The delta in shading is backported to Flourine SR2.

Comment by Luis Gomez [ 14/Jan/19 ]

Latest master test still fails:

https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netconf-csit-1node-userfeatures-all-neon/156/odl_1/odl1_karaf.log.gz

Comment by Robert Varga [ 14/Jan/19 ]

Okay, so partial success, we don't get org.apache.xerces in the way, but it seems we are getting a straight anyxml serialization failure. Last movement around this was YANGTOOLS-923, which was coming from NETCONF. JMorvay any ideas what may be going on here?

Comment by Robert Varga [ 14/Jan/19 ]

I don't quite like woodstox being in this stack trace:

	at com.sun.org.apache.xerces.internal.dom.ElementImpl.setAttributeNS(ElementImpl.java:659) ~[?:?]
	at com.ctc.wstx.dom.DOMOutputElement.addAttribute(DOMOutputElement.java:210) ~[32:com.fasterxml.woodstox.woodstox-core:5.0.3]
	at com.ctc.wstx.dom.WstxDOMWrappingWriter.outputAttribute(WstxDOMWrappingWriter.java:561) ~[32:com.fasterxml.woodstox.woodstox-core:5.0.3]
	at com.ctc.wstx.dom.WstxDOMWrappingWriter.writeAttribute(WstxDOMWrappingWriter.java:251) ~[32:com.fasterxml.woodstox.woodstox-core:5.0.3]
	at org.opendaylight.yangtools.yang.data.codec.xml.XMLStreamNormalizedNodeStreamWriter$DelegateWriterNoEndDoc.writeNamespace(XMLStreamNormalizedNodeStreamWriter.java:405) ~[509:org.opendaylight.yangtools.yang-data-codec-xml:2.1.7]
	at com.sun.org.apache.xalan.internal.xsltc.trax.SAX2StAXStreamWriter.startElement(SAX2StAXStreamWriter.java:176) ~[?:?]
Comment by Robert Varga [ 14/Jan/19 ]

.. which is coming from com.ctc.wstx.stax.WstxOutputFactory being an advertized XMLOutputFactory. Since it does some transformation, it may be interfering with the documented hack we have in place.

Comment by Robert Varga [ 14/Jan/19 ]

So the exception source reads:

                if (qname.equals("xmlns") && (namespaceURI == null
                    || !namespaceURI.equals(NamespaceContext.XMLNS_URI))
                    || (namespaceURI!=null && namespaceURI.equals(NamespaceContext.XMLNS_URI)
                    && !qname.equals("xmlns"))) {
                    String msg =
                        DOMMessageFormatter.formatMessage(
                                DOMMessageFormatter.DOM_DOMAIN,
                                "NAMESPACE_ERR",
                                null);
                    throw new DOMException(DOMException.NAMESPACE_ERR, msg);
                }

which looks awefully close to what we are trying to avoid in the code. We do need the input data here.

Comment by Robert Varga [ 14/Jan/19 ]

Btw. the anyxml fix is in yangtools-2.0.15, which is current Fluorine.

Comment by Robert Varga [ 14/Jan/19 ]

So my prime suspect is woodstox being pulled into the picture, and it is a jackson dependency. There has been some movement on master w.r.t. swagger, notably NETCONF-588. ecelgp can you try running it without installing apidocs, to see if it helps?

Comment by Luis Gomez [ 14/Jan/19 ]

The ERROR happens after this REST request:

PUT restconf/config/network-topology:network-topology/topology/topology-netconf/node/test-device
<node xmlns="urn:TBD:params:xml:ns:yang:network-topology">
<node-id>test-device</node-id>
<host xmlns="urn:opendaylight:netconf-node-topology">10.30.170.230</host>
<port xmlns="urn:opendaylight:netconf-node-topology">2830</port>
<username xmlns="urn:opendaylight:netconf-node-topology">admin</username>
<password xmlns="urn:opendaylight:netconf-node-topology">admin</password>
<tcp-only xmlns="urn:opendaylight:netconf-node-topology">false</tcp-only>
<keepalive-delay xmlns="urn:opendaylight:netconf-node-topology">0</keepalive-delay>
</node>

Comment by Luis Gomez [ 14/Jan/19 ]

Sure, will try right away.

Comment by Luis Gomez [ 14/Jan/19 ]

apidocs may not be related as this job does not install apidocs and still shows the problem: https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netconf-csit-1node-scale-only-neon/98/odl_1/odl1_karaf.log.gz

Comment by Luis Gomez [ 15/Jan/19 ]

Regression analysis:

Patches for MRI bump were filed by that time (odlparent-4.0.5, yangtools-2.1.6, mdsal-3.0.3):
https://git.opendaylight.org/gerrit/#/q/branch:master,525

Comment by Robert Varga [ 15/Jan/19 ]

That puts YANGTOOLS-923 into picture, but it does not explain why fluorine works, as it carries the equivalent fix since Dec 22. I don't see anything in odlparent v4.0.2..v4.0.5 which would cause this.

Comment by Robert Varga [ 15/Jan/19 ]

That having been said, I think part of the problem is the way yang-data-codec-xml performs the translation to DOM, i.e. the transformer (out of our reach) ends up adding the default namespace after an Element is created, rather than initializing its name with the namespace – and then we are doing a few questionable hacks to deal with the effects of that.

I suspect these hacks are what breaks with woodstox – perhaps we can post-process the DOM document to remove these, or get the transformer of out the picture completely by forwarding the input events ourselves... not sure yet.

Comment by Robert Varga [ 15/Jan/19 ]

Suspicion confirmed: if I add woodstox-core as a test dependency in yang-data-codec-xml, I am getting 9 failures and 3 errors – with two of those errors being the same thing as what the CSIT is finding.

 

Comment by Robert Varga [ 15/Jan/19 ]

https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/netconf-csit-1node-gate-userfeatures-all-neon/5/odl_1/odl1_karaf.log.gz shows the factories to be initialized to woodstox ones:

2019-01-15T11:35:45,302 | INFO  | features-3-thread-1 | NetconfUtil                      | 426 - org.opendaylight.netconf.util - 1.6.0.SNAPSHOT | Initializing XML factory initialized to class class com.ctc.wstx.stax.WstxOutputFactory instance com.ctc.wstx.stax.WstxOutputFactory@c8d838a
java.lang.Throwable: null
	at org.opendaylight.netconf.util.NetconfUtil.<clinit>(NetconfUtil.java:43) ~[?:?]
	at org.opendaylight.netconf.notifications.impl.ops.NotificationsTransformUtil.transform(NotificationsTransformUtil.java:88) ~[?:?]
	at org.opendaylight.netconf.notifications.impl.ops.NotificationsTransformUtil.transform(NotificationsTransformUtil.java:75) ~[?:?]
	at org.opendaylight.netconf.notifications.impl.NetconfNotificationManager$BaseNotificationPublisherReg.serializeNotification(NetconfNotificationManager.java:278) ~[?:?]
	at org.opendaylight.netconf.notifications.impl.NetconfNotificationManager$BaseNotificationPublisherReg.onCapabilityChanged(NetconfNotificationManager.java:284) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.NetconfCapabilityMonitoringService.onCapabilitiesChanged(NetconfCapabilityMonitoringService.java:225) ~[?:?]
	at org.opendaylight.netconf.notifications.impl.osgi.Activator$1.registerCapabilityListener(Activator.java:64) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.onAddNetconfOperationServiceFactory(AggregatedNetconfOperationServiceFactory.java:56) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.NetconfOperationServiceFactoryTracker.addingService(NetconfOperationServiceFactoryTracker.java:33) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.NetconfOperationServiceFactoryTracker.addingService(NetconfOperationServiceFactoryTracker.java:17) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:487) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:1004) ~[?:?]
	at org.opendaylight.netconf.notifications.impl.osgi.Activator.start(Activator.java:92) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:779) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl$3.run(BundleContextImpl.java:1) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:772) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:729) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:933) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:309) ~[?:?]
	at org.eclipse.osgi.container.Module.doStart(Module.java:581) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:449) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:402) ~[?:?]
	at org.apache.karaf.features.internal.service.BundleInstallSupportImpl.startBundle(BundleInstallSupportImpl.java:161) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.startBundle(FeaturesServiceImpl.java:1116) ~[?:?]
	at org.apache.karaf.features.internal.service.Deployer.deploy(Deployer.java:997) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision(FeaturesServiceImpl.java:1025) ~[?:?]
	at org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13(FeaturesServiceImpl.java:964) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]

and

2019-01-15T11:36:49,135 | INFO  | nioEventLoopGroupCloseable-6-3 | CopyConfig                       | 409 - org.opendaylight.netconf.mdsal-netconf-connector - 1.6.0.SNAPSHOT | Initializing XML factory initialized to class class com.ctc.wstx.stax.WstxOutputFactory instance com.ctc.wstx.stax.WstxOutputFactory@5c7fbd24
java.lang.Throwable: null
	at org.opendaylight.netconf.mdsal.connector.ops.CopyConfig.<clinit>(CopyConfig.java:67) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.OperationProvider.<init>(OperationProvider.java:35) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationService.<init>(MdsalNetconfOperationService.java:23) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationServiceFactory.createService(MdsalNetconfOperationServiceFactory.java:73) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationServiceFactory.createService(MdsalNetconfOperationServiceFactory.java:40) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory$AggregatedNetconfOperation.<init>(AggregatedNetconfOperationServiceFactory.java:130) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.createService(AggregatedNetconfOperationServiceFactory.java:109) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory$AggregatedNetconfOperation.<init>(AggregatedNetconfOperationServiceFactory.java:130) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.createService(AggregatedNetconfOperationServiceFactory.java:109) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getOperationServiceForAddress(NetconfServerSessionNegotiatorFactory.java:119) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getListener(NetconfServerSessionNegotiatorFactory.java:110) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getSessionNegotiator(NetconfServerSessionNegotiatorFactory.java:105) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerDispatcherImpl$ServerChannelInitializer.initializeSessionNegotiator(NetconfServerDispatcherImpl.java:64) ~[?:?]
	at org.opendaylight.netconf.nettyutil.AbstractChannelInitializer.initialize(AbstractChannelInitializer.java:35) ~[412:org.opendaylight.netconf.netty-util:1.6.0.SNAPSHOT]
	at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$1.initChannel(AbstractNetconfDispatcher.java:110) [412:org.opendaylight.netconf.netty-util:1.6.0.SNAPSHOT]
	at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:115) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:107) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:637) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.access$000(DefaultChannelPipeline.java:46) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1487) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1161) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:686) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:510) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:423) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:482) [61:io.netty.transport:4.1.31.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [58:io.netty.common:4.1.31.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [58:io.netty.common:4.1.31.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:466) [61:io.netty.transport:4.1.31.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897) [58:io.netty.common:4.1.31.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [58:io.netty.common:4.1.31.Final]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2019-01-15T11:36:49,144 | INFO  | nioEventLoopGroupCloseable-6-3 | AbstractGet                      | 409 - org.opendaylight.netconf.mdsal-netconf-connector - 1.6.0.SNAPSHOT | Initializing XML factory initialized to class class com.ctc.wstx.stax.WstxOutputFactory instance com.ctc.wstx.stax.WstxOutputFactory@4a1ad9d0
java.lang.Throwable: null
	at org.opendaylight.netconf.mdsal.connector.ops.get.AbstractGet.<clinit>(AbstractGet.java:55) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.OperationProvider.<init>(OperationProvider.java:35) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationService.<init>(MdsalNetconfOperationService.java:23) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationServiceFactory.createService(MdsalNetconfOperationServiceFactory.java:73) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationServiceFactory.createService(MdsalNetconfOperationServiceFactory.java:40) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory$AggregatedNetconfOperation.<init>(AggregatedNetconfOperationServiceFactory.java:130) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.createService(AggregatedNetconfOperationServiceFactory.java:109) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory$AggregatedNetconfOperation.<init>(AggregatedNetconfOperationServiceFactory.java:130) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.createService(AggregatedNetconfOperationServiceFactory.java:109) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getOperationServiceForAddress(NetconfServerSessionNegotiatorFactory.java:119) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getListener(NetconfServerSessionNegotiatorFactory.java:110) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getSessionNegotiator(NetconfServerSessionNegotiatorFactory.java:105) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerDispatcherImpl$ServerChannelInitializer.initializeSessionNegotiator(NetconfServerDispatcherImpl.java:64) ~[?:?]
	at org.opendaylight.netconf.nettyutil.AbstractChannelInitializer.initialize(AbstractChannelInitializer.java:35) ~[412:org.opendaylight.netconf.netty-util:1.6.0.SNAPSHOT]
	at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$1.initChannel(AbstractNetconfDispatcher.java:110) [412:org.opendaylight.netconf.netty-util:1.6.0.SNAPSHOT]
	at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:115) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:107) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:637) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.access$000(DefaultChannelPipeline.java:46) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1487) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1161) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:686) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:510) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:423) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:482) [61:io.netty.transport:4.1.31.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [58:io.netty.common:4.1.31.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [58:io.netty.common:4.1.31.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:466) [61:io.netty.transport:4.1.31.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897) [58:io.netty.common:4.1.31.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [58:io.netty.common:4.1.31.Final]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2019-01-15T11:36:49,155 | INFO  | nioEventLoopGroupCloseable-6-3 | RuntimeRpc                       | 409 - org.opendaylight.netconf.mdsal-netconf-connector - 1.6.0.SNAPSHOT | Initializing XML factory initialized to class class com.ctc.wstx.stax.WstxOutputFactory instance com.ctc.wstx.stax.WstxOutputFactory@30feb6b7
java.lang.Throwable: null
	at org.opendaylight.netconf.mdsal.connector.ops.RuntimeRpc.<clinit>(RuntimeRpc.java:69) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.OperationProvider.<init>(OperationProvider.java:35) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationService.<init>(MdsalNetconfOperationService.java:23) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationServiceFactory.createService(MdsalNetconfOperationServiceFactory.java:73) ~[?:?]
	at org.opendaylight.netconf.mdsal.connector.MdsalNetconfOperationServiceFactory.createService(MdsalNetconfOperationServiceFactory.java:40) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory$AggregatedNetconfOperation.<init>(AggregatedNetconfOperationServiceFactory.java:130) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.createService(AggregatedNetconfOperationServiceFactory.java:109) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory$AggregatedNetconfOperation.<init>(AggregatedNetconfOperationServiceFactory.java:130) ~[?:?]
	at org.opendaylight.netconf.impl.osgi.AggregatedNetconfOperationServiceFactory.createService(AggregatedNetconfOperationServiceFactory.java:109) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getOperationServiceForAddress(NetconfServerSessionNegotiatorFactory.java:119) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getListener(NetconfServerSessionNegotiatorFactory.java:110) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerSessionNegotiatorFactory.getSessionNegotiator(NetconfServerSessionNegotiatorFactory.java:105) ~[?:?]
	at org.opendaylight.netconf.impl.NetconfServerDispatcherImpl$ServerChannelInitializer.initializeSessionNegotiator(NetconfServerDispatcherImpl.java:64) ~[?:?]
	at org.opendaylight.netconf.nettyutil.AbstractChannelInitializer.initialize(AbstractChannelInitializer.java:35) ~[412:org.opendaylight.netconf.netty-util:1.6.0.SNAPSHOT]
	at org.opendaylight.netconf.nettyutil.AbstractNetconfDispatcher$1.initChannel(AbstractNetconfDispatcher.java:110) [412:org.opendaylight.netconf.netty-util:1.6.0.SNAPSHOT]
	at io.netty.channel.ChannelInitializer.initChannel(ChannelInitializer.java:115) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.ChannelInitializer.handlerAdded(ChannelInitializer.java:107) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.callHandlerAdded0(DefaultChannelPipeline.java:637) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.access$000(DefaultChannelPipeline.java:46) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline$PendingHandlerAddedTask.execute(DefaultChannelPipeline.java:1487) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.callHandlerAddedForAllHandlers(DefaultChannelPipeline.java:1161) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.DefaultChannelPipeline.invokeHandlerAddedIfNeeded(DefaultChannelPipeline.java:686) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.register0(AbstractChannel.java:510) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe.access$200(AbstractChannel.java:423) [61:io.netty.transport:4.1.31.Final]
	at io.netty.channel.AbstractChannel$AbstractUnsafe$1.run(AbstractChannel.java:482) [61:io.netty.transport:4.1.31.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [58:io.netty.common:4.1.31.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [58:io.netty.common:4.1.31.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:466) [61:io.netty.transport:4.1.31.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897) [58:io.netty.common:4.1.31.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [58:io.netty.common:4.1.31.Final]
	at java.lang.Thread.run(Thread.java:748) [?:?]

Now we just need to figure out how are we arriving at this implementation.

Comment by Robert Varga [ 15/Jan/19 ]

Okay, so this is something coming from Karaf, again. https://issues.apache.org/jira/browse/KARAF-5897 integrated in 4.2.2 means that the woodstox factory is now leaked across unrelated bundle trees Let's see how we can fix this....

Comment by Robert Varga [ 15/Jan/19 ]

So woodstox does not seem to be at fault, the error seems to lie in JDK's SAX2StAXStreamWriter assumptions about what XMLStreamWriter does, specifically how its startElement() side-steps emits namespaces and uses qName where localName is expected.

Since xalan-2.7.2 does not support StAX (it supports on JAXP-1.3), and http://apache-xml-project.6118.n7.nabble.com/StAXSources-with-Xalan-td21126.html indicates that the JDK fork is buggy (as seems to be the case above) and that there is now work being done on having xalan-J support StAX.

So it's time to ditch transformers at least in the DOM->StAX path, which is what is biting us here.

Comment by Robert Varga [ 24/Jan/19 ]

ecelgp the CSIT seems to be back up, modulo the change in empty data response. Can you update it, please?

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