Operating System: All
Platform: All

probably restarting the openflow bundles are causing these. We are moving the config parameters to a .cfg file in carbon, will c/p the changes here too. need to check if the error exists post that,

Can I see somehow logs ?

(In reply to Jozef Bacigal from comment #2)
> Can I see somehow logs ?

This is the error in the karaf console:

opendaylight-user@root>feature:install odl-restconf-all
opendaylight-user@root>feature:install odl-mdsal-all
opendaylight-user@root>feature:install odl-openflowplugin-southbound
opendaylight-user@root>feature:install odl-openflowplugin-flow-services
opendaylight-user@root>Exception in thread "Thread-132" io.netty.channel.unix.Errors$NativeIoException: bind() failed: Address already in use
at io.netty.channel.unix.Errors.newIOException(Errors.java:115)
at io.netty.channel.unix.Socket.bind(Socket.java:204)
at io.netty.channel.epoll.EpollServerSocketChannel.doBind(EpollServerSocketChannel.java:91)
at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:490)
at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1198)
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:481)
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:466)
at io.netty.channel.ChannelDuplexHandler.bind(ChannelDuplexHandler.java:38)
at io.netty.handler.logging.LoggingHandler.bind(LoggingHandler.java:197)
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:481)
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:466)
at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:944)
at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:203)
at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:350)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:307)
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
at java.lang.Thread.run(Thread.java:745)
Exception in thread "Thread-131" io.netty.channel.unix.Errors$NativeIoException: bind() failed: Address already in use
at io.netty.channel.unix.Errors.newIOException(Errors.java:115)
at io.netty.channel.unix.Socket.bind(Socket.java:204)
at io.netty.channel.epoll.EpollServerSocketChannel.doBind(EpollServerSocketChannel.java:91)
at io.netty.channel.AbstractChannel$AbstractUnsafe.bind(AbstractChannel.java:490)
at io.netty.channel.DefaultChannelPipeline$HeadContext.bind(DefaultChannelPipeline.java:1198)
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:481)
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:466)
at io.netty.channel.ChannelDuplexHandler.bind(ChannelDuplexHandler.java:38)
at io.netty.handler.logging.LoggingHandler.bind(LoggingHandler.java:197)
at io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:481)
at io.netty.channel.AbstractChannelHandlerContext.bind(AbstractChannelHandlerContext.java:466)
at io.netty.channel.DefaultChannelPipeline.bind(DefaultChannelPipeline.java:944)
at io.netty.channel.AbstractChannel.bind(AbstractChannel.java:203)
at io.netty.bootstrap.AbstractBootstrap$2.run(AbstractBootstrap.java:350)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:307)
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)
at java.lang.Thread.run(Thread.java:745)

====================================================================================
And this is the corresponding tailed logs:

2016-10-17 08:06:12,612 | INFO | erRestartService | printContainerRestartServiceImpl | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Restarting blueprint containers for bundle org.opendaylight.openflowplugin.blueprint-config_0.3.1.SNAPSHOT [289] and its dependent bundles [org.opendaylight.openflowplugin.impl_0.3.1.SNAPSHOT [286], org.opendaylight.openflowjava.openflow-protocol-impl_0.8.1.SNAPSHOT [276]]
2016-10-17 08:06:12,625 | INFO | erRestartService | BlueprintExtender | 15 - org.apache.aries.blueprint.core - 1.6.1 | Destroying BlueprintContainer for bundle org.opendaylight.openflowjava.openflow-protocol-impl/0.8.1.SNAPSHOT
2016-10-17 08:06:12,675 | INFO | erRestartService | BlueprintExtender | 15 - org.apache.aries.blueprint.core - 1.6.1 | Destroying BlueprintContainer for bundle org.opendaylight.openflowplugin.impl/0.3.1.SNAPSHOT
2016-10-17 08:06:12,707 | INFO | erRestartService | BlueprintExtender | 15 - org.apache.aries.blueprint.core - 1.6.1 | Destroying BlueprintContainer for bundle org.opendaylight.openflowplugin.blueprint-config/0.3.1.SNAPSHOT
2016-10-17 08:06:12,754 | INFO | erRestartService | printContainerRestartServiceImpl | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Restarting blueprint container for bundle org.opendaylight.openflowplugin.blueprint-config_0.3.1.SNAPSHOT [289] with paths [bundleentry://289.fwk195984832/org/opendaylight/blueprint/openflowplugin.xml]
2016-10-17 08:06:12,817 | INFO | erRestartService | BlueprintContainerImpl | 15 - org.apache.aries.blueprint.core - 1.6.1 | Bundle org.opendaylight.openflowplugin.blueprint-config/0.3.1.SNAPSHOT is waiting for dependencies [(objectClass=org.opendaylight.openflowjava.protocol.spi.connection.SwitchConnectionProviderFactory), (objectClass=org.opendaylight.openflowplugin.api.openflow.OpenFlowPluginProviderFactory)]
2016-10-17 08:06:12,818 | INFO | rint Extender: 3 | BlueprintContainerImpl | 15 - org.apache.aries.blueprint.core - 1.6.1 | Bundle org.opendaylight.openflowplugin.blueprint-config/0.3.1.SNAPSHOT is waiting for dependencies [(objectClass=org.opendaylight.openflowjava.protocol.spi.connection.SwitchConnectionProviderFactory), (objectClass=org.opendaylight.openflowplugin.api.openflow.OpenFlowPluginProviderFactory)]
2016-10-17 08:06:12,819 | INFO | rint Extender: 3 | BlueprintContainerImpl | 15 - org.apache.aries.blueprint.core - 1.6.1 | Bundle org.opendaylight.openflowplugin.blueprint-config/0.3.1.SNAPSHOT is waiting for dependencies [(objectClass=org.opendaylight.openflowjava.protocol.spi.connection.SwitchConnectionProviderFactory), (objectClass=org.opendaylight.openflowplugin.api.openflow.OpenFlowPluginProviderFactory)]
2016-10-17 08:06:12,820 | INFO | erRestartService | printContainerRestartServiceImpl | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Restarting blueprint container for bundle org.opendaylight.openflowplugin.impl_0.3.1.SNAPSHOT [286] with paths [bundleentry://286.fwk195984832/org/opendaylight/blueprint/commands.xml, bundleentry://286.fwk195984832/org/opendaylight/blueprint/openflowplugin-impl.xml]
2016-10-17 08:06:12,842 | INFO | rint Extender: 1 | BlueprintContainerImpl | 15 - org.apache.aries.blueprint.core - 1.6.1 | Bundle org.opendaylight.openflowplugin.blueprint-config/0.3.1.SNAPSHOT is waiting for dependencies [(objectClass=org.opendaylight.openflowjava.protocol.spi.connection.SwitchConnectionProviderFactory)]
2016-10-17 08:06:12,847 | INFO | ntAdminThread #3 | BlueprintBundleTracker | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Blueprint container for bundle org.opendaylight.openflowplugin.impl_0.3.1.SNAPSHOT [286] was successfully created
2016-10-17 08:06:12,847 | INFO | erRestartService | printContainerRestartServiceImpl | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Restarting blueprint container for bundle org.opendaylight.openflowjava.openflow-protocol-impl_0.8.1.SNAPSHOT [276] with paths [bundleentry://276.fwk195984832/org/opendaylight/blueprint/openflow-protocol-impl.xml]
2016-10-17 08:06:12,885 | INFO | ntAdminThread #4 | BlueprintBundleTracker | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Blueprint container for bundle org.opendaylight.openflowjava.openflow-protocol-impl_0.8.1.SNAPSHOT [276] was successfully created
2016-10-17 08:06:12,943 | INFO | rint Extender: 1 | penFlowPluginProviderFactoryImpl | 286 - org.opendaylight.openflowplugin.impl - 0.3.1.SNAPSHOT | Initializing new OFP southbound.
2016-10-17 08:06:12,960 | WARN | rint Extender: 1 | OpenFlowPluginProviderImpl | 286 - org.opendaylight.openflowplugin.impl - 0.3.1.SNAPSHOT | Error registering MBean {}
javax.management.InstanceAlreadyExistsException: MXBean already registered with name org.opendaylight.openflowplugin.impl.statistics.ofpspecific:type=MessageIntelligenceAgencyMXBean
at com.sun.jmx.mbeanserver.MXBeanLookup.addReference(MXBeanLookup.java:151)[:1.8.0_73]
at com.sun.jmx.mbeanserver.MXBeanSupport.register(MXBeanSupport.java:160)[:1.8.0_73]
at com.sun.jmx.mbeanserver.MBeanSupport.preRegister2(MBeanSupport.java:173)[:1.8.0_73]
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:930)[:1.8.0_73]
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)[:1.8.0_73]
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)[:1.8.0_73]
at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)[:1.8.0_73]
at org.opendaylight.openflowplugin.impl.OpenFlowPluginProviderImpl.registerMXBean(OpenFlowPluginProviderImpl.java:288)
at org.opendaylight.openflowplugin.impl.OpenFlowPluginProviderImpl.initialize(OpenFlowPluginProviderImpl.java:227)
at org.opendaylight.openflowplugin.impl.OpenFlowPluginProviderFactoryImpl.newInstance(OpenFlowPluginProviderFactoryImpl.java:68)
at Proxy3fb871b3_ca45_481d_9092_7545ffec048e.newInstance(Unknown Source)
at Proxy9bf2f9d3_0c0a_447e_8dad_4c59ebd43d38.newInstance(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.8.0_73]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)[:1.8.0_73]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)[:1.8.0_73]
at java.lang.reflect.Method.invoke(Method.java:497)[:1.8.0_73]
at org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:299)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:980)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromFactory(BeanRecipe.java:295)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:278)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:830)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:811)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:79)[15:org.apache.aries.blueprint.core:1.6.1]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_73]
at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:88)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:106)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.ServiceRecipe.createService(ServiceRecipe.java:285)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.ServiceRecipe.internalGetService(ServiceRecipe.java:252)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.ServiceRecipe.internalCreate(ServiceRecipe.java:149)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:79)[15:org.apache.aries.blueprint.core:1.6.1]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_73]
at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:88)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:255)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:186)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:724)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:411)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:276)[15:org.apache.aries.blueprint.core:1.6.1]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_73]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_73]
at org.apache.aries.blueprint.container.ExecutorServiceWrapper.run(ExecutorServiceWrapper.java:106)[15:org.apache.aries.blueprint.core:1.6.1]
at org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:48)[15:org.apache.aries.blueprint.core:1.6.1]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_73]
at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_73]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_73]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_73]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_73]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_73]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_73]
2016-10-17 08:06:12,990 | INFO | rint Extender: 1 | penFlowPluginProviderFactoryImpl | 286 - org.opendaylight.openflowplugin.impl - 0.3.1.SNAPSHOT | Configured values, StatisticsPollingOff:true, SwitchFeaturesMandatory:false, BarrierCountLimit:25600, BarrierTimeoutLimit:500, EchoReplyTimeout:2000, ThreadPoolMinThreads:1, ThreadPoolMaxThreads:32000, ThreadPoolTimeout:60, NotificationFlowRemovedOff:false
2016-10-17 08:06:13,041 | INFO | ntAdminThread #6 | BlueprintBundleTracker | 174 - org.opendaylight.controller.blueprint - 0.5.1.SNAPSHOT | Blueprint container for bundle org.opendaylight.openflowplugin.blueprint-config_0.3.1.SNAPSHOT [289] was successfully created

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

will provide the necessary relief.

If you disable statistics you should not see anything in operational inventory. But if statistics disabled you can alway make one time statistics gathering of all or just part you want update with RPC

opendaylight-direct-statistics

But anyway this is why Shuva did create all setting in cfg file to be able do changes no the fly.

(In reply to Jozef Bacigal from comment #5)
> If you disable statistics you should not see anything in operational
> inventory. But if statistics disabled you can alway make one time statistics
> gathering of all or just part you want update with RPC
>
> opendaylight-direct-statistics
>
> But anyway this is why Shuva did create all setting in cfg file to be able
> do changes no the fly.

But with statistics turned off, will not itemLifecycleListener be non-null thereby call itemLifecycleListener.onAdded() on rpc success?

even with changing on the fly, although no stats goes on the wire, i am not able to push any flows, i donot see flow_mods going on the wire

(In reply to Shuva Jyoti Kar from comment #6)
> (In reply to Jozef Bacigal from comment #5)
> > If you disable statistics you should not see anything in operational
> > inventory. But if statistics disabled you can alway make one time statistics
> > gathering of all or just part you want update with RPC
> >
> > opendaylight-direct-statistics
> >
> > But anyway this is why Shuva did create all setting in cfg file to be able
> > do changes no the fly.
>
>
> But with statistics turned off, will not itemLifecycleListener be non-null
> thereby call itemLifecycleListener.onAdded() on rpc success?

i do understand this part now, as LifeCycleSource salFlowService is currently not registered in MdSalRegistrationUtils,so itemLifecycleListener is never set.

If LifeCycleSource is registered, then special RPC "change-statistics-work-mode" need to be called yet. Thereafter flows are written to the operational DS.

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

This patch, already merged, should help to use direct statistics RPC.

I'll close this bug because if used with changing cfg file it is working fine. With the yang configuration is not properly implemented in plugin. Created a new milestone to improve this through configuration DS and change the statistics gathering behavior changes.

OPNFLWPLUG-804