-
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:
-
Story Points:2
-
Epic Link:
-
Sprint:VOLTHA 2.9 - Release sprint
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