-
Type:
Bug
-
Status: Resolved (View Workflow)
-
Priority:
High
-
Resolution: Done
-
Affects Version/s: VOLTHA v2.8
-
Fix Version/s: VOLTHA v2.8
-
Component/s: olt
-
Labels:
-
Story Points:8
-
Epic Link:
There are 3 issues in the scale test:
A) Some ONUs receive the default EAPOL flow twice (before and after subscriber provisioning)
B) Meter ID Mismatch\"kv-store-meter-id\":1,\"meter-id-in-flow\":2
C) Some ONUs receive a delete request for a flow that was never installed
The analized build is: https://jenkins.opencord.org/view/voltha-scale-measurements/job/voltha-scale-measurements-master-2-16-32-att-subscribers/1951/
A) Duplicated EAPOL Flow
One of the ONUs that has a duplicated default EAPOL flow is BBSM000a0c1b.
The first flow add arrives at:
default/bbsim0-fd5d54dcc-977k8[bbsim]: time="2021-07-06T20:49:27.977848356Z" level=debug msg="OLT receives FlowAdd for ONU" AllocId=1049 ClassifierEthType=888e ClassifierIVid=0 ClassifierOPbits=255 ClassifierOVid=4091 Cookie=91479371253813104 DstPort=0 FlowId=5079900198780574711 FlowType=upstream GemportId=1049 InnerVlan=0 IntfId=12 IpProto=0 OnuId=27 OnuSn=BBSM000a0c1b OuterVlan=4091 PbitToGemport="map[]" PortNo=49584 ReplicateFlow=false SrcPort=0 UniID=0 module=ONU
Subscriber is provisioned at
default/voltha-infra-onos-classic-1[onos-classic]: 20:50:58.773 INFO [Olt] Call to provision subscriber at of:00000a0a0a0a0a0a/49584 And ONOS logs an error in the EAPOL FLOW (with vlans) installation: default/voltha-infra-onos-classic-1[onos-classic]: 20:51:16.156 INFO [OltFlowService] Processing EAPOL with Bandwidth profile User_Bandwidth1 on of:00000a0a0a0a0a0a/49584[BBSM000a0c1b-1] default/voltha-infra-onos-classic-1[onos-classic]: 20:51:16.163 INFO [OltFlowService] Meter 2 for User_Bandwidth1 on of:00000a0a0a0a0a0a/49584[BBSM000a0c1b-1] exists. Installing EAPOL trap flow default/voltha-infra-onos-classic-0[onos-classic]: 20:51:19.954 INFO [AaaManager] Auth event STARTED for of:00000a0a0a0a0a0a/49584 default/voltha-infra-onos-classic-1[onos-classic]: 20:51:26.371 ERROR [OltFlowService] Eapol filter -127062018 for of:00000a0a0a0a0a0a/49584[BBSM000a0c1b-1] with meter 2 failed installation because FLOWINSTALLATIONFAILED
In the openolt adapter you can see the flow is added:
default/voltha1-voltha-adapter-openolt-664c944d96-nn9s6[adapter-open-olt]: {"level":"info","ts":"2021-07-06T20:51:19.589Z","caller":"core/openolt_flowmgr.go:1205","msg":"adding-ethType-flow-to-device","instanceId":"voltha1-voltha-adapter-openolt-664c944d96-nn9s6","op-id":"7e7dd920d006f6b3","op-name":"openflow-flow-add","task-id":"0ff37eca1a8f7736","task-name":"kafka-rpc-update_flows_incrementally","onu-id":27,"port-no":49584,"alloc-id":1040,"gemport-id":1040,"vlan-id":4091,"flow":"id:5079900198780574711 priority:10000 cookie:91479371253813104 match:<type:OFPMT_OXM oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<port:536870924 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_ETH_TYPE eth_type:34958 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_VLAN_VID vlan_vid:8187 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_TUNNEL_ID tunnel_id:49584 > > > instructions:<type:4 actions:<actions:<output:<port:2147483645 max_len:65509 > > > > instructions:<type:6 meter:<meter_id:1 > > instructions:<type:2 write_metadata:<metadata:1151514404601200640 > > ","ethType":34958,"intf-id":12}
Then BBSim receives a second default EAPOL flow:
default/bbsim0-fd5d54dcc-977k8[bbsim]: time="2021-07-06T20:51:19.590653868Z" level=debug msg="OLT receives FlowAdd for ONU" AllocId=1040 ClassifierEthType=888e ClassifierIVid=0 ClassifierOPbits=255 ClassifierOVid=4091 Cookie=91479371253813104 DstPort=0 FlowId=5079900198780574711 FlowType=upstream GemportId=1040 InnerVlan=0 IntfId=12 IpProto=0 OnuId=27 OnuSn=BBSM000a0c1b OuterVlan=4091 PbitToGemport="map[]" PortNo=49584 ReplicateFlow=false SrcPort=0 UniID=0 module=ONU
In the ONOS flows list I see the correct flow:
ADDED, bytes=0, packets=0, table=0, priority=10000, selector=[IN_PORT:49584, ETH_TYPE:eapol], treatment=[immediate=[OUTPUT:CONTROLLER, VLAN_PUSH:vlan, VLAN_ID:2540], meter=METER:2, metadata=METADATA:9ec004000000002/0]
B) Meter ID mismatch
Investigating ONU BBSM000a0b1e (as this error appeared while investingating C). This ONU has port number 45536 in ONOS on device 00000a0a0a0a0a0a
This issue is most likely caused by unaccounted for duplicated EAPOL flow with the default VLAN.
C) Delete for missing flow
Investigating ONU BBSM000a0b1e as it logs multiple times
default/bbsim0-fd5d54dcc-977k8[bbsim]: time="2021-07-06T20:53:51.352178798Z" level=debug msg="OLT receives FlowRemove" AllocId=0 Cookie=0 FlowId=12070428983351933837 FlowType=upstream GemportId=0 IntfId=11 OnuId=30 PbitToGemport="map[]" PortNo=0 ReplicateFlow=false UniID=0 module=OLT default/bbsim0-fd5d54dcc-977k8[bbsim]: time="2021-07-06T20:53:51.385549782Z" level=error msg="Can't find Onu" IntfId=11 OnuId=30 err="Cannot find Onu by flowId 12070428983351933837" module=OLT
In the openolt adapter the first reference to the flows is at 20:52:46.937:
default/voltha1-voltha-adapter-openolt-664c944d96-nn9s6[adapter-open-olt]: {"level":"info","ts":"2021-07-06T20:52:46.937Z","caller":"core/openolt.go:275","msg":"Update_flows_incrementally","instanceId":"voltha1-voltha-adapter-openolt-664c944d96-nn9s6","op-id":"494e337154db198d","op-name":"openflow-flow-add","task-id":"0829770f2a326879","task-name":"kafka-rpc-update_flows_incrementally","device-id":"9fbdca5c-a26d-482e-87cd-a1533a05ef59","flows":"to_add:<items:<id:12070428983351933837 priority:10000 cookie:91479368831052670 match:<type:OFPMT_OXM oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<port:536870923 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_ETH_TYPE eth_type:2048 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_VLAN_VID vlan_vid:6520 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_IP_PROTO ip_proto:17 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_UDP_SRC udp_src:68 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_UDP_DST udp_dst:67 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_TUNNEL_ID tunnel_id:45536 > > > instructions:<type:4 actions:<actions:<output:<port:2147483645 max_len:65509 > > > > instructions:<type:6 meter:<meter_id:2 > > instructions:<type:2 write_metadata:<metadata:274877906946 > > > > to_remove:<> ","flowMetadata":"meters:<flags:5 meter_id:2 bands:<type:OFPMBT_DROP rate:30000 burst_size:10000 > bands:<type:OFPMBT_DROP rate:230000 burst_size:11000 > bands:<type:OFPMBT_DROP rate:100000 > > "}
and contains the flow to be added.
At 20:52:46.941 the flow add fails because of a meter-id mismatch:
default/voltha1-voltha-adapter-openolt-664c944d96-nn9s6[adapter-open-olt]: {"level":"error","ts":"2021-07-06T20:52:46.941Z","caller":"core/openolt_flowmgr.go:744","msg":"CreateSchedulerQueues-failed-upstream","instanceId":"voltha1-voltha-adapter-openolt-664c944d96-nn9s6","op-name":"openflow-flow-add","task-id":"0829770f2a326879","task-name":"kafka-rpc-update_flows_incrementally","op-id":"494e337154db198d","meter-id":2,"device-id":"9fbdca5c-a26d-482e-87cd-a1533a05ef59","err":"invalid-value: [{\"device-id\":\"9fbdca5c-a26d-482e-87cd-a1533a05ef59\",\"kv-store-meter-id\":1,\"meter-id-in-flow\":2,\"unsupported\":\"meter-id\"}]","onu-id":30,"uni-id":0,"intf-id":11,"stacktrace":"github.com/opencord/voltha-lib-go/v5/pkg/log.clogger.Errorw\n\t/go/src/vendor/github.com/opencord/voltha-lib-go/v5/pkg/log/log.go:612\ngithub.com/opencord/voltha-openolt-adapter/internal/pkg/core.(*OpenOltFlowMgr).createTcontGemports\n\t/go/src/internal/pkg/core/openolt_flowmgr.go:744\ngithub.com/opencord/voltha-openolt-adapter/internal/pkg/core.(*OpenOltFlowMgr).processAddFlow\n\t/go/src/internal/pkg/core/openolt_flowmgr.go:362\ngithub.com/opencord/voltha-openolt-adapter/internal/pkg/core.(*OpenOltFlowMgr).AddFlow\n\t/go/src/internal/pkg/core/openolt_flowmgr.go:2194\ngithub.com/opencord/voltha-openolt-adapter/internal/pkg/core.(*OpenOltFlowMgr).perOnuFlowHandlerRoutine\n\t/go/src/internal/pkg/core/openolt_flowmgr.go:2070"}
Because of this error the flow is never sent to the device.
A second later, at 20:52:47.932, we receive a request to delete the same flow:
default/voltha1-voltha-adapter-openolt-664c944d96-nn9s6[adapter-open-olt]: {"level":"info","ts":"2021-07-06T20:52:47.932Z","caller":"core/openolt.go:275","msg":"Update_flows_incrementally","instanceId":"voltha1-voltha-adapter-openolt-664c944d96-nn9s6","op-name":"openflow-flow-add","task-id":"59973b6642102ddf","task-name":"kafka-rpc-update_flows_incrementally","op-id":"494e337154db198d","device-id":"9fbdca5c-a26d-482e-87cd-a1533a05ef59","flows":"to_add:<> to_remove:<items:<id:12070428983351933837 priority:10000 cookie:91479368831052670 match:<type:OFPMT_OXM oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<port:536870923 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_ETH_TYPE eth_type:2048 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_VLAN_VID vlan_vid:6520 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_IP_PROTO ip_proto:17 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_UDP_SRC udp_src:68 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_UDP_DST udp_dst:67 > > oxm_fields:<oxm_class:OFPXMC_OPENFLOW_BASIC ofb_field:<type:OFPXMT_OFB_TUNNEL_ID tunnel_id:45536 > > > instructions:<type:4 actions:<actions:<output:<port:2147483645 max_len:65509 > > > > instructions:<type:6 meter:<meter_id:2 > > instructions:<type:2 write_metadata:<metadata:274877906946 > > > > ","flowMetadata":"meters:<flags:5 meter_id:2 bands:<type:OFPMBT_DROP rate:30000 burst_size:10000 > bands:<type:OFPMBT_DROP rate:230000 burst_size:11000 > bands:<type:OFPMBT_DROP rate:100000 > > "}
And this request fails as BBSim doesn't know about the flow.