[#CONTROLLER-70] RESTCONF knocked out after controller restart with saved NETCONF config

[CONTROLLER-70] RESTCONF knocked out after controller restart with saved NETCONF config Created: 29/Nov/13 Updated: 25/Jul/23 Resolved: 29/Nov/13
Status:	Resolved
Project:	controller
Component/s:	config
Affects Version/s:	None
Fix Version/s:	None

Type:

Improvement

Reporter:

Jan Medved

Assignee:

Unassigned

Resolution:

Done

Votes:

Labels:

None

Remaining Estimate:

Not Specified

Time Spent:

Not Specified

Original Estimate:

Not Specified

Environment:

Operating System: Mac OS
Platform: PC

Attachments:

opendaylight.log

Description

After the controller was brought up, successfully configured for netconf, and connected to yuma and to itself, it was restarted. The restart resulted in the console output at the end of this email.

After the controller restart, when I try to connect to RESTCONF, the following error message was seen:

'Restcof is not initialized yet. Please try again later'

After restoring the original (I.e. after mvn clean install, W/o netconf) controller configuration, RESTCONF was operational again

'No data exists.'

Then, netconf was configured with yangcli-pro as follows:

[255] get
[256] get-config
[257] 2
[258] merge modules/module
[259] netconf-thread-boss
[260] netty-threadgroup-fixed
[261] 1
[262] 2
[263] merge modules/module
[264] netconf-thread-worker
[265] netty-threadgroup-fixed
[266] 1
[267] 5
[268] commit
[269] merge modules/module
[270] controller
[271] sal-netconf-connector
[272] 12
[273] 127.0.0.1
[274] 8383
[275] true
[276] foo
[277] bar
[278] dom-broker-osgi-registry
[279] ref_dom-broker
[280] netty-threadgroup
[281] ref_netconf-thread-boss
[282] netty-threadgroup
[283] ref_netconf-thread-worker
[284] commit

After that, I could see the controller in inventory and could get its data in XML. Restarting the controller resulted again in the 'Restcof unavailable' message.

The controller logs and the config file are attached.

===============================
Console printout from controller start:
===============================

2013-11-28 20:10:51.460 PST [nioEventLoopGroup-2-4] INFO o.o.c.n.u.m.SendErrorExceptionUtil - Sending error <rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0">
<rpc-error>
<error-type>application</error-type>
<error-tag>operation-failed</error-tag>
<error-severity>error</error-severity>

<error-info>
<operation_failed>{logback={singleton=ExceptionMessageWithStackTrace [message=null, stackTrace=[org.opendaylight.controller.config.yang.logback.config.LogbackModule.validateLoggersObjects(LogbackModule.java:58), org.opendaylight.controller.config.yang.logback.config.LogbackModule.validate(LogbackModule.java:42), org.opendaylight.controller.config.manager.impl.ConfigTransactionControllerImpl.validate_noLocks(ConfigTransactionControllerImpl.java:296), org.opendaylight.controller.config.manager.impl.ConfigTransactionControllerImpl.validateConfig(ConfigTransactionControllerImpl.java:280), sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method), sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:606), sun.reflect.misc.Trampoline.invoke(MethodUtil.java:75), sun.reflect.GeneratedMethodAccessor163.invoke(Unknown Source), sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43), java.lang.reflect.Method.invoke(Method.java:606), sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:279), com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:193), com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:175), com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:117), com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:54), com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237), com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138), com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252), com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819), com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801), com.sun.jmx.mbeanserver.MXBeanProxy$InvokeHandler.invoke(MXBeanProxy.java:150), com.sun.jmx.mbeanserver.MXBeanProxy.invoke(MXBeanProxy.java:167), javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:252), com.sun.proxy.$Proxy90.validateConfig(Unknown Source), org.opendaylight.controller.config.util.ConfigTransactionJMXClient.validateConfig(ConfigTransactionJMXClient.java:99), org.opendaylight.controller.netconf.confignetconfconnector.transactions.TransactionProvider.validateTestTransaction(TransactionProvider.java:132), org.opendaylight.controller.netconf.confignetconfconnector.operations.editconfig.EditConfig.test(EditConfig.java:115), org.opendaylight.controller.netconf.confignetconfconnector.operations.editconfig.EditConfig.executeTests(EditConfig.java:94), org.opendaylight.controller.netconf.confignetconfconnector.operations.editconfig.EditConfig.getResponseInternal(EditConfig.java:65), org.opendaylight.controller.netconf.confignetconfconnector.operations.editconfig.EditConfig.handle(EditConfig.java:213), org.opendaylight.controller.netconf.confignetconfconnector.operations.AbstractConfigNetconfOperation.handle(AbstractConfigNetconfOperation.java:42), org.opendaylight.controller.netconf.util.mapping.AbstractNetconfOperation.handle(AbstractNetconfOperation.java:79), org.opendaylight.controller.netconf.impl.osgi.NetconfOperationRouterImpl$NetconfOperationExecution.execute(NetconfOperationRouterImpl.java:256), org.opendaylight.controller.netconf.impl.mapping.operations.DefaultCommit.doFilter(DefaultCommit.java:78), org.opendaylight.controller.netconf.impl.osgi.NetconfOperationRouterImpl$1.execute(NetconfOperationRouterImpl.java:179), org.opendaylight.controller.netconf.impl.osgi.NetconfOperationRouterImpl.executeOperationWithHighestPriority(NetconfOperationRouterImpl.java:184), org.opendaylight.controller.netconf.impl.osgi.NetconfOperationRouterImpl.onNetconfMessage(NetconfOperationRouterImpl.java:147), org.opendaylight.controller.netconf.impl.NetconfServerSessionListener.processDocument(NetconfServerSessionListener.java:105), org.opendaylight.controller.netconf.impl.NetconfServerSessionListener.onMessage(NetconfServerSessionListener.java:71), org.opendaylight.controller.netconf.impl.NetconfServerSessionListener.onMessage(NetconfServerSessionListener.java:31), org.opendaylight.controller.netconf.api.NetconfSession.handleMessage(NetconfSession.java:61), org.opendaylight.controller.netconf.api.NetconfSession.handleMessage(NetconfSession.java:22), org.opendaylight.protocol.framework.AbstractProtocolSession.channelRead0(AbstractProtocolSession.java:45), io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:98), io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:337), io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:323), io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:173), io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:337), io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:323), io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:173), io.netty.channel.DefaultChannelHandlerContext.invokeChannelRead(DefaultChannelHandlerContext.java:337), io.netty.channel.DefaultChannelHandlerContext.fireChannelRead(DefaultChannelHandlerContext.java:323), io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:785), io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:100), io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:480), io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:447), io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:341), io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101), java.lang.Thread.run(Thread.java:724)]]}}</operation_failed>
</error-info>
</rpc-error>
</rpc-reply>

2013-11-28 20:10:52.345 PST [ConfigPersister-registrator] WARN o.o.c.n.p.i.ConfigPersisterNotificationHandler - Can not load last configuration, operation failed
2013-11-28 20:10:52.346 PST [ConfigPersister-registrator] ERROR o.o.c.l.b.i.UncaughtExceptionHandler - Uncaught ExceptionHandler:
java.lang.IllegalStateException: Can not load last configuration, operation failed: <rpc-reply xmlns="urn:ietf:params:xml:ns:netconf:base:1.0" message-id="persister_edit">
<rpc-error>
<error-type>application</error-type>
<error-tag>operation-failed</error-tag>
<error-severity>error</error-severity>

at org.opendaylight.controller.netconf.persist.impl.ConfigPersisterNotificationHandler.checkIsOk(ConfigPersisterNotificationHandler.java:283) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPersisterNotificationHandler.pushLastConfig(ConfigPersisterNotificationHandler.java:261) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPersisterNotificationHandler.init(ConfigPersisterNotificationHandler.java:97) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.osgi.ConfigPersisterActivator$1.run(ConfigPersisterActivator.java:66) ~[na:na]
at java.lang.Thread.run(Thread.java:724) ~[na:1.7.0_25]

osgi>
osgi>
osgi>
osgi> 2013-11-28 20:11:18 PST [com.sun.jersey.spi.container.ContainerResponse] SEVERE com.sun.jersey.spi.container.ContainerResponse logException Mapped exception to response: 503 (Service Unavailable)
org.opendaylight.controller.sal.restconf.impl.ResponseException
at org.opendaylight.controller.sal.restconf.impl.ControllerContext.checkPreconditions(ControllerContext.java:102)
at org.opendaylight.controller.sal.restconf.impl.ControllerContext.findModule(ControllerContext.java:137)
at org.opendaylight.controller.sal.restconf.impl.ControllerContext.toInstanceIdentifier(ControllerContext.java:121)
at org.opendaylight.controller.sal.restconf.impl.RestconfImpl.resolveInstanceIdentifier(RestconfImpl.java:216)
at org.opendaylight.controller.sal.restconf.impl.RestconfImpl.readData(RestconfImpl.java:90)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.ResourceObjectRule.accept(ResourceObjectRule.java:100)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1511)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1442)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1391)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1381)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:538)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:716)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:848)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.catalina.filters.CorsFilter.handleNonCORS(CorsFilter.java:440)
at org.apache.catalina.filters.CorsFilter.doFilter(CorsFilter.java:179)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:581)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:309)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1002)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:585)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:724)

Comments

Comment by Jan Medved [ 29/Nov/13 ]

Attachment opendaylight.log has been added with description: Controller log file

Comment by Tony Tkacik [ 29/Nov/13 ]

Controller was knocked by loading stored configuration for logback
not netconf client default configuration.

The MD-SAL was not started, because config subsystem failed transaction
for logback.

Moved bug to config.

Comment by Tomas Olvecky [ 29/Nov/13 ]

This should be fixed in master now.

Generated at Wed Feb 07 19:52:06 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.

[CONTROLLER-70] RESTCONF knocked out after controller restart with saved NETCONF config Created: 29/Nov/13 Updated: 25/Jul/23 Resolved: 29/Nov/13