[VOL-4513] If events on the same ports happen very quickly they might be ignored in the OLT app - OpenCORD JIRA

XML

Word

Printable

Details

Type: Bug
Status: Resolved (View Workflow)
Priority: High
Resolution: Done
Affects Version/s: VOLTHA v2.9
Fix Version/s: VOLTHA v2.9
Component/s: onos-olt
Labels:
- onf

Story Points:
2
Epic Link:
ONOS app improvements
Sprint:
VOLTHA 2.9 - Release sprint

Description

https://jenkins.opencord.org/view/VOLTHA-2.X-Tests/job/build_flex-ocp-cord_Default_voltha_master_test/866/robot/report/FailureScenarios/log.html failed because of this reason.

OfAgent was restarted at: "16:01:06.331"

voltha/voltha-voltha-ofagent-788cdcd9d9-mz8tl[ofagent]: {"level":"info","ts":"2021-12-07T16:01:09.888Z","caller":"ofagent/main.go:125","msg":"ofagent-config","instanceId":"voltha-voltha-ofagent-788cdcd9d9-mz8tl","config":{"OFControllerEndPoints":["voltha-infra-onos-classic-0.voltha-infra-onos-classic-hs.infra.svc:6653","voltha-infra-onos-classic-1.voltha-infra-onos-classic-hs.infra.svc:6653","voltha-infra-onos-classic-2.voltha-infra-onos-classic-hs.infra.svc:6653"],"VolthaApiEndPoint":"voltha-voltha-api.voltha.svc:55555","LogLevel":"DEBUG","Banner":true,"Version":false,"ProbeEndPoint":":8080","CpuProfile":"","MemProfile":"","DeviceListRefreshInterval":15000000000,"ConnectionRetryDelay":3000000000,"ConnectionMaxRetries":0,"KVStoreType":"etcd","KVStoreTimeout":60000000000,"KVStoreAddress":"{{ .Values.global.voltha_infra_name }}-etcd.{{ .Values.global.voltha_infra_namespace }}.svc:2379","InstanceID":"voltha-voltha-ofagent-788cdcd9d9-mz8tl","TraceEnabled":false,"TraceAgentAddress":"voltha-infra-voltha-tracing-jaeger-agent.infra.svc:6831","LogCorrelationEnabled":true}}

Subscriber on 512 was provisioned at:

infra/voltha-infra-onos-classic-1[onos-classic]: 16:01:12.917 INFO  [Olt] Provisioning subscriber on of:0000b86a974385f7/512[ALPHe3d1cea3-1]

Device disconnected from ONOS at:

infra/voltha-infra-onos-classic-0[onos-classic]: 16:01:34.954 INFO  [Olt$OltDeviceListener] Device of:0000b86a974385f7 availability changed to false, but ports are still available, assuming temporary disconnection.

Port 512 went down

infra/voltha-infra-onos-classic-1[onos-classic]: 16:01:35.008 INFO  [Olt$OltDeviceListener] OltDeviceListener receives event PORT_UPDATED for port of:0000b86a974385f7/512[ALPHe3d1cea3-1] with status DISABLED on device of:0000b86a974385f7

Port 512 comes back up

infra/voltha-infra-onos-classic-1[onos-classic]: 16:01:35.021 INFO  [Olt$OltDeviceListener] OltDeviceListener receives event PORT_UPDATED for port of:0000b86a974385f7/512[ALPHe3d1cea3-1] with status ENABLED on device of:0000b86a974385f7

A request to remove the subscriber is put on the queue

infra/voltha-infra-onos-classic-1[onos-classic]: 16:01:35.127 INFO [Olt] Adding subscriber to queue: of:0000b86a974385f7/512[ALPHe3d1cea3-1] with status REMOVED and subscriber true

A request to add the subscriber back (as the port came back up) is not processed:

infra/voltha-infra-onos-classic-1[onos-classic]: 16:01:35.127 DEBUG [Olt] Not adding subscriber to queue as already present: of:0000b86a974385f7/512[ALPHe3d1cea3-1] with status ADDED

Fix
A piece of code was checking to avoid duplicated entries in the queue:

-        if (!q.contains(sub)) {
-            log.info("Adding subscriber to queue: {} with status {} and subscriber {}",
-                    portWithName(sub.port), sub.status, sub.hasSubscriber);
-            q.add(sub);
-        } else {
-            log.debug("Not adding subscriber to queue as already present: {} with status {}",
-                    portWithName(sub.port), sub.status);
-            // no need to update the queue in the map if nothing has changed
-            return;
-        }

as a `Add -> Remove -> Add` should still result in an Add