Operating System: All
Platform: All

BTW this is reprodcible with latest Boron.

One question that i have is does the flow with alien id in the Oper-DS remain forever?

Once you get an alien ID further flow delete/push attempts also produce alien ID, if this is your question.

BTW this issue could be the same affecting the FRS test (random alien ID).

(In reply to Luis Gomez from comment #3)
> Once you get an alien ID further flow delete/push attempts also produce
> alien ID, if this is your question.

There is a window in which the stats polling fetches the flow from the switch faster than the rpc add-flow callback succeeds resulting in the alien id.

If we increase the stats polling interval, the window reduces. Manually its really difficult to hit that , its quite surprising to see that you are able to reproduce it deterministically.

I think there is something else:

• After connecting switch it normally works.
• After retrying a few times delete/add flow there is a moment after which it consistently fails to match.
• The only way to get rid of the failure is to restart the switch connection.

Another observation is that I have to give 5 secs in automation between delete and create the flow to consitently reproduce.

I tried it around 10/11 times manually today and could reproduce it only once.

FYI I wrote a test that consistently reproduces the issue:

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

Hopefully this gets merged soon.

Based on comment #1, I believe this bug is targeted for Boron.

Shuva, is there a way to disable the stats polling? if this is really interfering we can run the test without stats collection and see what happens.

We can use PUT @ http://localhost:8181/restconf/config/openflow-provider-config:openflow-provider-config/ with the following configuration

{
"openflow-provider-config":

}

To turn stats polling off. Please do it before connecting switches since the last time i checked it would restart the modules and with switches connected, it can result in huge errors.

FYI https://git.opendaylight.org/gerrit/#/c/46718/
patch it can be configured in a cfg file that will persist reboots

Hi Shuva,

When I disable stats polling I do not get anything in inventory or topology when switch connects, I think something is broken when doing that because I also see this exception in karaf console:

opendaylight-user@root>Exception in thread "Thread-297" 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)

did you change it before connecting the switch ?

Yes, also in a second attempt I do not get the exception but still the switch does not show in topology or inventory. Have you tried this lately? I am using latest Boron.

had tried it about a month back, will try and keep you posted

(In reply to Shuva Jyoti Kar from comment #16)
> had tried it about a month back, will try and keep you posted

Also try provisioning a flow to see if that triggers an update ?

Just tried with boron release and same issue so I opened this:

https://bugs.opendaylight.org/show_bug.cgi?id=6941

BR/Luis

For this specific issue I have 2 more findings:

• The isse is reproducible with any flow body.
• The time between the flow is deleted from oper DS and we repush the flow has to be 5s, with more or less time, it is more difficult to reproduce.

In partcular this is what the automation does (consistently fails):

Loop on:

Sleep 5
FlowLib.Create Flow Variables For Suite From XML File ${XmlsDir}/${flowfile}
FlowLib.Add Flow Via Restconf ${switch_idx} ${table_id} ${data}
BuiltIn.Wait Until Keyword Succeeds 10s 1s FlowLib.Check Operational Flow ${True} ${data}
FlowLib.Check Datastore Presence ${flowfile} ${True} ${True} ${False} ${True}
FlowLib.Delete Flow Via Restconf ${switch_idx} ${table_id} ${flow_id}
BuiltIn.Wait Until Keyword Succeeds 10s 1s FlowLib.Check Operational Flow ${False} ${data}
FlowLib.Check Datastore Presence ${flowfile} ${False} ${False} ${True}

I tried the 5 sec delay between deletion and repush , and i could see the alien flow id once, but the next sec i retried it was showing the actual one. I tried about 23 times today, no luck.

I tried with this flow

<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<flow xmlns="urn:opendaylight:flow:inventory">
<hard-timeout>0</hard-timeout>
<idle-timeout>0</idle-timeout>
<priority>2</priority>
<flow-name>flow2</flow-name>
<match>
<ethernet-match>
<ethernet-type>
<type>2048</type>
</ethernet-type>
</ethernet-match>
<ipv4-destination>10.0.17.2/32</ipv4-destination>
</match>
<id>2</id>
<table_id>0</table_id>
<instructions>
<instruction>
<order>0</order>
<apply-actions>
<action>
<output-action>
<output-node-connector>1</output-node-connector>
</output-action>
<order>0</order>
</action>
</apply-actions>
</instruction>
</instructions>
</flow>

Shuva I was wrong, the issue shows normally with big flows (lot of matches like the one I posted in the bug) and I was also able to reproduce it by just adding (no deleting) different big flows every 8 secs. I will update the CI test to show this too.

No issues Luis. I will try it with the flow that you had reported initially with and then come back tomorrow. thanks

Here it is:

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

(In reply to Luis Gomez from comment #24)
> Here it is:
>
> https://git.opendaylight.org/gerrit/#/c/46984

I am trying with ovs2.4 and getting OFP_BMC_BAD_WILDCARDS errors. Any other example flow that will work with ovs2.4 ?

(In reply to Shuva Jyoti Kar from comment #25)
> (In reply to Luis Gomez from comment #24)
> > Here it is:
> >
> > https://git.opendaylight.org/gerrit/#/c/46984
>
> I am trying with ovs2.4 and getting OFP_BMC_BAD_WILDCARDS errors. Any other
> example flow that will work with ovs2.4 ?

Hello Shuva,

You can use flow from LUIS on the very top.

You just need to change

<ipv6-source>1234:5678:9ABC:DEF0:FDCD:A987:6543:210F/76</ipv6-source>

to

<ipv6-source>1234:5678:9ABC:DEF0:FDC0::/76</ipv6-source>

Miro

<flow xmlns="urn:opendaylight:flow:inventory">
<strict>false</strict>
<flow-name>FooXf21</flow-name>
<id>144</id>
<cookie_mask>255</cookie_mask>
<cookie>21</cookie>
<table_id>2</table_id>
<priority>21</priority>
<installHw>false</installHw>
<instructions>
<instruction>
<order>0</order>
<apply-actions>
<action>
<order>0</order>
<dec-nw-ttl/>
</action>
</apply-actions>
</instruction>
</instructions>
<match>
<ethernet-match>
<ethernet-type>
<type>34525</type>
</ethernet-type>
</ethernet-match>
<ipv6-source>1234:5678:9abc:def0:fdc0::/76</ipv6-source>
<ipv6-destination>fe80::2acf:e9ff:fe21:6431/128</ipv6-destination>
<metadata>
<metadata>12345</metadata>
</metadata>
<ip-match>
<ip-protocol>17</ip-protocol>
<ip-dscp>8</ip-dscp>
<ip-ecn>3</ip-ecn>
</ip-match>
<udp-source-port>25364</udp-source-port>
<udp-destination-port>8080</udp-destination-port>
</match>
</flow>

Strangely enough 13/13 times i tried this but donot see this in my set-up, with 8 secs delay between additions, and a total 10-15 flows .

@Miroslav any points you have

Hello Shuva,

I think this happen when flow is removed from config, and statistics(in aprox. 3 seconds interval) bring the flow.

It is not present in DeviceFlowRegistry, so it will create flow with alien id.

I was able to reproduce. I will attach the karaf log.

We have an idea, what could fix it. I will try.

If you have some idea, please feel free to do it.

Thanks,
Miro

Attachment device-flow-registry-karaf.log has been added with description: karaf log

(In reply to Miroslav Macko from comment #28)
> Hello Shuva,
>
> I think this happen when flow is removed from config, and statistics(in
> aprox. 3 seconds interval) bring the flow.
>
> It is not present in DeviceFlowRegistry, so it will create flow with alien
> id.
>
> I was able to reproduce. I will attach the karaf log.
>
> We have an idea, what could fix it. I will try.
>
> If you have some idea, please feel free to do it.
>
> Thanks,
> Miro

Yes Miroslav. i too guessed the same. Please try your fix, i am yet to arrive at a solution to address it permanently. However i feel with stats turned off, we might not see this problem

Shuva, please save the flow miroslav sent as f21.xml and run this script in same folder:

#!/bin/bash
for i in `seq 1 5`
do
echo "Add flow ${i} time"
curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X PUT http://localhost:8181/restconf/config/opendaylight-inventory:nodes/node/openflow:1/table/2/flow/144 -d @f21.xml
sleep 5
echo "Get Flow in Oper"
curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X GET http://localhost:8181/restconf/operational/opendaylight-inventory:nodes/node/openflow:1/table/2
echo -e "\nDelete flow"
curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X DELETE http://localhost:8181/restconf/config/opendaylight-inventory:nodes/node/openflow:1/table/2/flow/144
sleep 6
done

At least in my laptop I am getting alien ID very consistent before script reaches 5 attempts.

I think the failure is even more reproducible when we add some fix sleep after stats has been updated in controller, like we do in the robot test.

Definitely it has to be with stats collection, if I use this script sleeping 6 secs after stats are received for deleted flow, I hit the issue much more often:

#!/bin/bash
for i in `seq 1 5`
do
echo "Add flow ${i} time"
curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X PUT http://localhost:8181/restconf/config/opendaylight-inventory:nodes/node/openflow:1/table/2/flow/144 -d @f21.xml
while true
do
STRING=`curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X GET http://localhost:8181/restconf/operational/opendaylight-inventory:nodes/node/openflow:1/table/2 2>/dev/null`
if [[ ${STRING} == "<priority>21</priority>" ]]; then
break
fi
done
echo "Get Flow in Oper"
curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X GET http://localhost:8181/restconf/operational/opendaylight-inventory:nodes/node/openflow:1/table/2
echo -e "\nDelete flow"
curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X DELETE http://localhost:8181/restconf/config/opendaylight-inventory:nodes/node/openflow:1/table/2/flow/144
while true
do
STRING=`curl -u admin:admin -H "Expect:" -H "Content-Type:application/xml" -H "Accept:application/xml" -X GET http://localhost:8181/restconf/operational/opendaylight-inventory:nodes/node/openflow:1/table/2 2>/dev/null`
if [[ ${STRING} != "<priority>21</priority>" ]]; then
break
fi
done
sleep 6
done

Luis,

With https://git.opendaylight.org/gerrit/#/c/47004/, turning off stats would be easy. And with stats off we might not see this issue

Hi guys,

@Shuva if stats are turned off, flow will get to the operational only with reconciliation. Right? Is it ok?

@Luis I have pushed the patch

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

Could you please test it?

Thank you,
Miro

(In reply to Miroslav Macko from comment #35)
> Hi guys,
>
> @Shuva if stats are turned off, flow will get to the operational only with
> reconciliation. Right? Is it ok?
>
> @Luis I have pushed the patch
>
> https://git.opendaylight.org/gerrit/#/c/47085/
>
> Could you please test it?
>
> Thank you,
> Miro

If stats are turned off, then by current design they will appear in the Oper-Ds on rpcs success. It would be better not to change that behaviour since it gives a fair guarantee to applications whether the flow succeeded or not.

Could not access your patch, could you please add me to it.

Hello Shuva,

But this is not added by RPCs. It is put to config and it is added to operational by FRM or FRS using statistics. Isn't it?

Thanks,
Miro

Hi Miroslav, this is the result of your patch:

https://logs.opendaylight.org/releng/jenkins092/openflowplugin-csit-1node-flow-services-only-carbon/172/archives/log.html.gz

It does fix the alien ID issue but for some reason it breaks the RPC update operation.

Hello Luis,

I see. I will check it. Thanks a lot.

Miro

(In reply to Miroslav Macko from comment #37)
> Hello Shuva,
>
> But this is not added by RPCs. It is put to config and it is added to
> operational by FRM or FRS using statistics. Isn't it?
>
> Thanks,
> Miro

You are correct Miroslav!
I only wanted to point out that without statistics, on the addFlow rpc success we write the flow to the operational

(In reply to Luis Gomez from comment #38)
> Hi Miroslav, this is the result of your patch:
>
> https://logs.opendaylight.org/releng/jenkins092/openflowplugin-csit-1node-
> flow-services-only-carbon/172/archives/log.html.gz
>
> It does fix the alien ID issue but for some reason it breaks the RPC update
> operation.

Luis, in the CSIT TCs, do we do some kind of a retry to check if the flow is in the operational DS? Or is it a one time check?

Hi guys,

I have pushed the patch:

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

It should work already.

But I need to check behavior with statistics turned off yet.

I will do it tomorrow.

Thanks.
Miro

In the failing test the flows seem to be updated but no flow shows up in operational after 3 sec. There are multiple retries after during 5 secs (check updated flow) but in the last retry I still see no flow. I can retrigger the test to see if this consisten or just a transient failure.

transient discarded, something in Miroslav's patch impacts stats collection after RPC update operation.

https://jenkins.opendaylight.org/releng/view/openflowplugin/job/openflowplugin-csit-1node-flow-services-only-carbon/175/

BR/Luis

(In reply to Luis Gomez from comment #44)
> transient discarded, something in Miroslav's patch impacts stats collection
> after RPC update operation.
>
> https://jenkins.opendaylight.org/releng/view/openflowplugin/job/
> openflowplugin-csit-1node-flow-services-only-carbon/175/
>
> BR/Luis

Hello Luis,

This test(175) ran on this patch?

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

Thanks,
Miro

No, still the old patch, you want to run the test with the new patch? I can do that too.

Hello Luis,

It would be fine, if you will test it. It should fix RPC updates in test:

/test/csit/suites/openflowplugin/Flows_Additional_TCs/Stat_Manager_extended/020_SM_sal_add_upd_del_flows.robot

But I need to test use case when statistics are off.

I will let you know, when it is done.

Thanks a lot,
Miro

Hello Luis,

I have pushed the patch:

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

Could you please test it?

I am not seeing the problem with "add port" locally.

Please let me know, it the problem persists.

Thank you,
Miro

Pushed on master:
https://git.opendaylight.org/gerrit/#/c/47138/

and stable/bo
https://git.opendaylight.org/gerrit/#/c/47320

Yes, this is fixed now.

We have to reopen this bug for stable boron as current fix has been reverted because it changes plugin behavior.

Are there plans to fix it now, or can we retarget for Boron-SR3 for more time?

Lower down priority as this does not impact forwarding, just operational info + some conditions are required in order to reproduce (e.g. big flows pushed at very specific interval)

Pushed correct fix to Gerrit: https://git.opendaylight.org/gerrit/#/c/52237/

Tested it with Luis reproduction steps, and without this patch, the bug was still present, but after my changes, I was not able to reproduce it anymore. Also, tested the case, that previous patch was not checking for, and that is manually adding flow via OVS CLI, and it got properly propagated to operational.

Luis, can you check this and verify that it resolves this issue?

Hi Tomas, to verify you just need to run the test-openflowplugin-core, and check this job: https://logs.opendaylight.org/releng/jenkins092/openflowplugin-csit-1node-flow-services-only-carbon/532/archives/log.html.gz

It seems the issue is still there (see the OPNFLWPLUG-796 at the end).

Hi Tomas, to verify you just need to run the test-openflowplugin-core, and check this job: https://logs.opendaylight.org/releng/jenkins092/openflowplugin-csit-1node-flow-services-only-carbon/532/archives/log.html.gz

It seems the issue is still there (see the OPNFLWPLUG-796 at the end).

I think current patch is good.

Patch was merged, so I think that this one can be closed, right?

Tomas, can you cherry pick for stable/boron?

Reopen so we do not forget to cherry-pick.

Created cherry-pick for stable/boron here: https://git.opendaylight.org/gerrit/#/c/53545/

Raise to blocker - so that the patch can be added in SR 3.

Changing milestone to SR4.

Patch that fixes performance regression: https://git.opendaylight.org/gerrit/#/c/53972/

Can be cherry-picked to boron (requires also re-revert of original patch).

Sounds good, we can merge all these changes after boron is unlocked.

Merged into Boron. Closing bug.