[VOL-3655] Hardening: Cope with vendor-specific error-results of ONUs due to unsupported OMCI-MEs
[VOL-3642] Optimize logging with level "info" used for scale test
plus minor refactorizations
Change-Id: Ib2127048dc11bba55632494fb8aa77355b958900
diff --git a/VERSION b/VERSION
index 097bb1e..702b965 100644
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-0.1.14-dev142
+0.1.14-dev143
diff --git a/internal/pkg/onuadaptercore/device_handler.go b/internal/pkg/onuadaptercore/device_handler.go
index 3f53050..7328abd 100644
--- a/internal/pkg/onuadaptercore/device_handler.go
+++ b/internal/pkg/onuadaptercore/device_handler.go
@@ -90,6 +90,22 @@
cOnuActivatedEvent = "ONU_ACTIVATED"
)
+const (
+ // device reasons
+ drActivatingOnu = "activating-onu"
+ drStartingOpenomci = "starting-openomci"
+ drDiscoveryMibsyncComplete = "discovery-mibsync-complete"
+ drInitialMibDownloaded = "initial-mib-downloaded"
+ drTechProfileConfigDownloadSuccess = "tech-profile-config-download-success"
+ drOmciFlowsPushed = "omci-flows-pushed"
+ drOmciAdminLock = "omci-admin-lock"
+ drOnuReenabled = "onu-reenabled"
+ drStoppingOpenomci = "stopping-openomci"
+ drRebooting = "rebooting"
+ drOmciFlowsDeleted = "omci-flows-deleted"
+ drTechProfileConfigDeleteSuccess = "tech-profile-config-delete-success"
+)
+
//deviceHandler will interact with the ONU ? device.
type deviceHandler struct {
deviceID string
@@ -249,13 +265,13 @@
msgBody := msg.GetBody()
onuIndication := &oop.OnuIndication{}
if err := ptypes.UnmarshalAny(msgBody, onuIndication); err != nil {
- logger.Warnw("cannot-unmarshal-onu-indication-msg-body", log.Fields{
+ logger.Warnw("onu-ind-request-cannot-unmarshal-msg-body", log.Fields{
"device-id": dh.deviceID, "error": err})
return err
}
onuOperstate := onuIndication.GetOperState()
- logger.Debugw("inter-adapter-recv-onu-ind", log.Fields{"device-id": dh.deviceID,
+ logger.Infow("onu-ind-request", log.Fields{"device-id": dh.deviceID,
"OnuId": onuIndication.GetOnuId(),
"AdminState": onuIndication.GetAdminState(), "OperState": onuOperstate,
"SNR": onuIndication.GetSerialNumber()})
@@ -275,6 +291,8 @@
func (dh *deviceHandler) processInterAdapterTechProfileDownloadReqMessage(
msg *ic.InterAdapterMessage) error {
+ logger.Infow("tech-profile-download-request", log.Fields{"device-id": dh.deviceID})
+
pDevEntry := dh.getOnuDeviceEntry(true)
if pDevEntry == nil {
logger.Errorw("No valid OnuDevice - aborting", log.Fields{"device-id": dh.deviceID})
@@ -354,6 +372,8 @@
func (dh *deviceHandler) processInterAdapterDeleteGemPortReqMessage(
msg *ic.InterAdapterMessage) error {
+ logger.Infow("delete-gem-port-request", log.Fields{"device-id": dh.deviceID})
+
pDevEntry := dh.getOnuDeviceEntry(true)
if pDevEntry == nil {
logger.Errorw("No valid OnuDevice - aborting", log.Fields{"device-id": dh.deviceID})
@@ -411,6 +431,8 @@
func (dh *deviceHandler) processInterAdapterDeleteTcontReqMessage(
msg *ic.InterAdapterMessage) error {
+ logger.Infow("delete-tcont-request", log.Fields{"device-id": dh.deviceID})
+
pDevEntry := dh.getOnuDeviceEntry(true)
if pDevEntry == nil {
logger.Errorw("No valid OnuDevice - aborting", log.Fields{"device-id": dh.deviceID})
@@ -646,7 +668,7 @@
//note that disableDevice sequences in some 'ONU active' state may yield also
// "tech...delete-success" or "omci-flow-deleted" according to further received requests in the end
// - inblock state checking to prevent possibly unneeded processing (on command repitition)
- if dh.deviceReason != "omci-admin-lock" {
+ if dh.deviceReason != drOmciAdminLock {
//disable-device shall be just a UNi/ONU-G related admin state setting
//all other configurations/FSM's shall not be impacted and shall execute as required by the system
@@ -667,15 +689,10 @@
//TODO with VOL-3045/VOL-3046: return the error and stop further processing
logger.Errorw("error-updating-device-state", log.Fields{"device-id": dh.deviceID, "error": err})
}
-
- logger.Debugw("DeviceReasonUpdate upon disable", log.Fields{
- "reason": "omci-admin-lock", "device-id": dh.deviceID})
// DeviceReason to update acc.to modified py code as per beginning of Sept 2020
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "omci-admin-lock"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-updating-reason-state", log.Fields{"device-id": dh.deviceID, "error": err})
- }
- dh.deviceReason = "omci-admin-lock"
+
+ //TODO with VOL-3045/VOL-3046: catch and return error, valid for all occurrences in the codebase
+ _ = dh.deviceReasonUpdate(drOmciAdminLock, false)
}
}
}
@@ -854,12 +871,9 @@
logger.Errorw("error-updating-device-state", log.Fields{"device-id": dh.deviceID, "error": err})
return err
}
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "rebooting"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-updating-reason-state", log.Fields{"device-id": dh.deviceID, "error": err})
+ if err := dh.deviceReasonUpdate(drRebooting, false); err != nil {
return err
}
- dh.deviceReason = "rebooting"
dh.ReadyForSpecificOmciConfig = false
return nil
}
@@ -884,12 +898,13 @@
dh.device.Root = false
dh.device.Vendor = "OpenONU"
dh.device.Model = "go"
- dh.device.Reason = "activating-onu"
- dh.deviceReason = "activating-onu"
+ dh.device.Reason = drActivatingOnu
+ dh.deviceReason = drActivatingOnu
dh.logicalDeviceID = dh.deviceID // really needed - what for ??? //TODO!!!
if !dh.reconciling {
+ logger.Infow("DeviceUpdate", log.Fields{"deviceReason": dh.device.Reason, "device-id": dh.deviceID})
_ = dh.coreProxy.DeviceUpdate(context.TODO(), dh.device)
} else {
logger.Debugw("reconciling - don't notify core about DeviceUpdate",
@@ -1156,9 +1171,9 @@
dh.setOnuDeviceEntry(deviceEntry, onuTechProfProc)
// fire deviceEntry ready event to spread to possibly waiting processing
dh.deviceEntrySet <- true
- logger.Infow("onuDeviceEntry-added", log.Fields{"device-id": dh.deviceID})
+ logger.Debugw("onuDeviceEntry-added", log.Fields{"device-id": dh.deviceID})
} else {
- logger.Infow("onuDeviceEntry-add: Device already exists", log.Fields{"device-id": dh.deviceID})
+ logger.Debugw("onuDeviceEntry-add: Device already exists", log.Fields{"device-id": dh.deviceID})
}
// might be updated with some error handling !!!
return nil
@@ -1206,16 +1221,7 @@
logger.Errorw("No valid OnuDevice -aborting", log.Fields{"device-id": dh.deviceID})
return fmt.Errorf("no valid OnuDevice: %s", dh.deviceID)
}
- if !dh.reconciling {
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "starting-openomci"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-DeviceReasonUpdate to starting-openomci", log.Fields{"device-id": dh.deviceID, "error": err})
- }
- } else {
- logger.Debugw("reconciling - don't notify core about DeviceReasonUpdate to starting-openomci",
- log.Fields{"device-id": dh.deviceID})
- }
- dh.deviceReason = "starting-openomci"
+ _ = dh.deviceReasonUpdate(drStartingOpenomci, dh.reconciling)
/* this might be a good time for Omci Verify message? */
verifyExec := make(chan bool)
@@ -1355,7 +1361,7 @@
func (dh *deviceHandler) updateInterface(onuind *oop.OnuIndication) error {
//state checking to prevent unneeded processing (eg. on ONU 'unreachable' and 'down')
// (but note that the deviceReason may also have changed to e.g. TechProf*Delete_Success in between)
- if dh.deviceReason != "stopping-openomci" {
+ if dh.deviceReason != drStoppingOpenomci {
logger.Debugw("updateInterface-started - stopping-device", log.Fields{"device-id": dh.deviceID})
//stop all running FSM processing - make use of the DH-state as mirrored in the deviceReason
@@ -1392,17 +1398,12 @@
dh.disableUniPortStateUpdate()
- dh.deviceReason = "stopping-openomci"
dh.ReadyForSpecificOmciConfig = false
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "stopping-openomci"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-DeviceReasonUpdate to stopping-openomci",
- log.Fields{"device-id": dh.deviceID, "error": err})
+ if err := dh.deviceReasonUpdate(drStoppingOpenomci, false); err != nil {
// abort: system behavior is just unstable ...
return err
}
-
logger.Debugw("call DeviceStateUpdate upon update interface", log.Fields{"ConnectStatus": voltha.ConnectStatus_UNREACHABLE,
"OperStatus": voltha.OperStatus_DISCOVERED, "device-id": dh.deviceID})
if err := dh.coreProxy.DeviceStateUpdate(context.TODO(), dh.deviceID,
@@ -1479,22 +1480,8 @@
func (dh *deviceHandler) processMibDatabaseSyncEvent(devEvent OnuDeviceEvent) {
logger.Debugw("MibInSync event received, adding uni ports and locking the ONU interfaces", log.Fields{"device-id": dh.deviceID})
- if !dh.reconciling {
- //initiate DevStateUpdate
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "discovery-mibsync-complete"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-DeviceReasonUpdate to mibsync-complete", log.Fields{
- "device-id": dh.deviceID, "error": err})
- } else {
- logger.Infow("dev reason updated to MibSync complete", log.Fields{"device-id": dh.deviceID})
- }
- } else {
- logger.Debugw("reconciling - don't notify core about DeviceReasonUpdate to mibsync-complete",
- log.Fields{"device-id": dh.deviceID})
- }
- //set internal state anyway - as it was done
- dh.deviceReason = "discovery-mibsync-complete"
+ _ = dh.deviceReasonUpdate(drDiscoveryMibsyncComplete, dh.reconciling)
pDevEntry := dh.getOnuDeviceEntry(false)
i := uint8(0) //UNI Port limit: see MaxUnisPerOnu (by now 16) (OMCI supports max 255 p.b.)
if unigInstKeys := pDevEntry.pOnuDB.getSortedInstKeys(me.UniGClassID); len(unigInstKeys) > 0 {
@@ -1590,20 +1577,7 @@
logger.Debugw("reconciling - don't notify core about DeviceStateUpdate to ACTIVE",
log.Fields{"device-id": dh.deviceID})
}
- if !dh.reconciling {
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "initial-mib-downloaded"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-DeviceReasonUpdate to initial-mib-downloaded",
- log.Fields{"device-id": dh.deviceID, "error": err})
- } else {
- logger.Infow("dev reason updated to initial-mib-downloaded", log.Fields{"device-id": dh.deviceID})
- }
- } else {
- logger.Debugw("reconciling - don't notify core about DeviceReasonUpdate to initial-mib-downloaded",
- log.Fields{"device-id": dh.deviceID})
- }
- //set internal state anyway - as it was done
- dh.deviceReason = "initial-mib-downloaded"
+ _ = dh.deviceReasonUpdate(drInitialMibDownloaded, dh.reconciling)
dh.ReadyForSpecificOmciConfig = true
// *** should generate UniUnlockStateDone event *****
if dh.pUnlockStateFsm == nil {
@@ -1638,14 +1612,9 @@
logger.Errorw("error-updating-device-state", log.Fields{"device-id": dh.deviceID, "error": err})
}
- logger.Debugw("DeviceReasonUpdate upon disable", log.Fields{
- "reason": "omci-admin-lock", "device-id": dh.deviceID})
+ logger.Debugw("DeviceReasonUpdate upon disable", log.Fields{"reason": drOmciAdminLock, "device-id": dh.deviceID})
// DeviceReason to update acc.to modified py code as per beginning of Sept 2020
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "omci-admin-lock"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-updating-reason-state", log.Fields{"device-id": dh.deviceID, "error": err})
- }
- dh.deviceReason = "omci-admin-lock"
+ _ = dh.deviceReasonUpdate(drOmciAdminLock, false)
//transfer the modified logical uni port state
dh.disableUniPortStateUpdate()
@@ -1661,13 +1630,9 @@
}
logger.Debugw("DeviceReasonUpdate upon re-enable", log.Fields{
- "reason": "onu-reenabled", "device-id": dh.deviceID})
+ "reason": drOnuReenabled, "device-id": dh.deviceID})
// DeviceReason to update acc.to modified py code as per beginning of Sept 2020
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "onu-reenabled"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-updating-reason-state", log.Fields{"device-id": dh.deviceID, "error": err})
- }
- dh.deviceReason = "onu-reenabled"
+ _ = dh.deviceReasonUpdate(drOnuReenabled, false)
//transfer the modified logical uni port state
dh.enableUniPortStateUpdate()
@@ -1678,23 +1643,9 @@
logger.Debugw("OmciAniConfigDone event received", log.Fields{"device-id": dh.deviceID})
// attention: the device reason update is done based on ONU-UNI-Port related activity
// - which may cause some inconsistency
- if dh.deviceReason != "tech-profile-config-download-success" {
+ if dh.deviceReason != drTechProfileConfigDownloadSuccess {
// which may be the case from some previous actvity even on this UNI Port (but also other UNI ports)
- if !dh.reconciling {
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "tech-profile-config-download-success"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-DeviceReasonUpdate to tech-profile-config-download-success",
- log.Fields{"device-id": dh.deviceID, "error": err})
- } else {
- logger.Infow("update dev reason to tech-profile-config-download-success",
- log.Fields{"device-id": dh.deviceID})
- }
- } else {
- logger.Debugw("reconciling - don't notify core about DeviceReasonUpdate to tech-profile-config-download-success",
- log.Fields{"device-id": dh.deviceID})
- }
- //set internal state anyway - as it was done
- dh.deviceReason = "tech-profile-config-download-success"
+ _ = dh.deviceReasonUpdate(drTechProfileConfigDownloadSuccess, dh.reconciling)
}
if dh.reconciling {
go dh.reconcileDeviceFlowConfig()
@@ -1703,18 +1654,9 @@
logger.Debugw("OmciAniResourceRemoved event received", log.Fields{"device-id": dh.deviceID})
// attention: the device reason update is done based on ONU-UNI-Port related activity
// - which may cause some inconsistency
- if dh.deviceReason != "tech-profile-config-delete-success" {
+ if dh.deviceReason != drTechProfileConfigDeleteSuccess {
// which may be the case from some previous actvity even on this ONU port (but also other UNI ports)
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "tech-profile-config-delete-success"); err != nil {
- //TODO with VOL-3045/VOL-3046: return the error and stop further processing
- logger.Errorw("error-DeviceReasonUpdate to tech-profile-config-delete-success",
- log.Fields{"device-id": dh.deviceID, "error": err})
- } else {
- logger.Infow("update dev reason to tech-profile-config-delete-success",
- log.Fields{"device-id": dh.deviceID})
- }
- //set internal state anyway - as it was done
- dh.deviceReason = "tech-profile-config-delete-success"
+ _ = dh.deviceReasonUpdate(drTechProfileConfigDeleteSuccess, false)
}
}
}
@@ -1726,40 +1668,18 @@
// - which may cause some inconsistency
if aDevEvent == OmciVlanFilterAddDone {
- if dh.deviceReason != "omci-flows-pushed" {
+ if dh.deviceReason != drOmciFlowsPushed {
// which may be the case from some previous actvity on another UNI Port of the ONU
// or even some previous flow add activity on the same port
- if !dh.reconciling {
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "omci-flows-pushed"); err != nil {
- logger.Errorw("error-DeviceReasonUpdate to omci-flows-pushed",
- log.Fields{"device-id": dh.deviceID, "error": err})
- } else {
- logger.Infow("updated dev reason to omci-flows-pushed",
- log.Fields{"device-id": dh.deviceID})
- }
- } else {
- logger.Debugw("reconciling - don't notify core about DeviceReasonUpdate to omci-flows-pushed",
- log.Fields{"device-id": dh.deviceID})
- }
- //set internal state anyway - as it was done
- dh.deviceReason = "omci-flows-pushed"
-
+ _ = dh.deviceReasonUpdate(drOmciFlowsPushed, dh.reconciling)
if dh.reconciling {
go dh.reconcileMetrics()
}
}
} else {
- if dh.deviceReason != "omci-flows-deleted" {
+ if dh.deviceReason != drOmciFlowsDeleted {
//not relevant for reconcile
- if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, "omci-flows-deleted"); err != nil {
- logger.Errorw("error-DeviceReasonUpdate to omci-flows-deleted",
- log.Fields{"device-id": dh.deviceID, "error": err})
- } else {
- logger.Infow("updated dev reason to omci-flows-deleted",
- log.Fields{"device-id": dh.deviceID})
- }
- //set internal state anyway - as it was done
- dh.deviceReason = "omci-flows-deleted"
+ _ = dh.deviceReasonUpdate(drOmciFlowsDeleted, false)
}
}
}
@@ -1922,10 +1842,10 @@
chLSFsm := make(chan Message, 2048)
var sFsmName string
if aAdminState {
- logger.Infow("createLockStateFSM", log.Fields{"device-id": dh.deviceID})
+ logger.Debugw("createLockStateFSM", log.Fields{"device-id": dh.deviceID})
sFsmName = "LockStateFSM"
} else {
- logger.Infow("createUnlockStateFSM", log.Fields{"device-id": dh.deviceID})
+ logger.Debugw("createUnlockStateFSM", log.Fields{"device-id": dh.deviceID})
sFsmName = "UnLockStateFSM"
}
@@ -2383,6 +2303,23 @@
"device-id": dh.deviceID, "called from": aCallerIdent})
}
+func (dh *deviceHandler) deviceReasonUpdate(deviceReason string, dontNotifyCore bool) error {
+
+ dh.deviceReason = deviceReason
+ if !dontNotifyCore {
+ //TODO with VOL-3045/VOL-3046: return the error and stop further processing at calling position
+ if err := dh.coreProxy.DeviceReasonUpdate(context.TODO(), dh.deviceID, deviceReason); err != nil {
+ logger.Errorw("DeviceReasonUpdate: error",
+ log.Fields{"deviceReason": deviceReason, "device-id": dh.deviceID, "error": err})
+ return err
+ }
+ logger.Infow("DeviceReasonUpdate: success", log.Fields{"deviceReason": deviceReason, "device-id": dh.deviceID})
+ return nil
+ }
+ logger.Infow("Don't notify core about DeviceReasonUpdate", log.Fields{"deviceReason": deviceReason, "device-id": dh.deviceID})
+ return nil
+}
+
func (dh *deviceHandler) combineErrorStrings(errS ...error) error {
var errStr string = ""
for _, err := range errS {
diff --git a/internal/pkg/onuadaptercore/mib_download.go b/internal/pkg/onuadaptercore/mib_download.go
index 74881f8..48abc65 100644
--- a/internal/pkg/onuadaptercore/mib_download.go
+++ b/internal/pkg/onuadaptercore/mib_download.go
@@ -60,7 +60,7 @@
}
func (onuDeviceEntry *OnuDeviceEntry) enterBridgeInitState(e *fsm.Event) {
- logger.Infow("MibDownload FSM - starting bridge config port loop", log.Fields{
+ logger.Debugw("MibDownload FSM - starting bridge config port loop", log.Fields{
"in state": e.FSM.Current(), "device-id": onuDeviceEntry.deviceID})
go onuDeviceEntry.performInitialBridgeSetup()
}
@@ -124,7 +124,7 @@
case TestMsg:
msg, _ := message.Data.(TestMessage)
if msg.TestMessageVal == AbortMessageProcessing {
- logger.Infow("MibDownload abort ProcessMsg", log.Fields{"for device-id": onuDeviceEntry.deviceID})
+ logger.Debugw("MibDownload abort ProcessMsg", log.Fields{"for device-id": onuDeviceEntry.deviceID})
break loop
}
logger.Warnw("MibDownload unknown TestMessage", log.Fields{"device-id": onuDeviceEntry.deviceID, "MessageVal": msg.TestMessageVal})
@@ -137,7 +137,7 @@
}
}
- logger.Infow("End MibDownload Msg processing", log.Fields{"for device-id": onuDeviceEntry.deviceID})
+ logger.Debugw("End MibDownload Msg processing", log.Fields{"for device-id": onuDeviceEntry.deviceID})
}
func (onuDeviceEntry *OnuDeviceEntry) handleOmciMibDownloadMessage(msg OmciMessage) {
diff --git a/internal/pkg/onuadaptercore/mib_sync.go b/internal/pkg/onuadaptercore/mib_sync.go
index 90dd7bb..7d52b36 100644
--- a/internal/pkg/onuadaptercore/mib_sync.go
+++ b/internal/pkg/onuadaptercore/mib_sync.go
@@ -446,26 +446,10 @@
return nil
}
}
- } else if msgObj.Result == me.UnknownInstance {
- logger.Debugw("MibSync FSM - Unknown Instance in GetResponse Data", log.Fields{"device-id": oo.deviceID, "data-fields": msgObj})
- entityID := oo.PDevOmciCC.pLastTxMeInstance.GetEntityID()
- if msgObj.EntityClass == oo.PDevOmciCC.pLastTxMeInstance.GetClassID() && msgObj.EntityInstance == entityID {
- meInstance := oo.PDevOmciCC.pLastTxMeInstance.GetName()
- switch meInstance {
- case "IpHostConfigData":
- logger.Debugf("MibSync FSM - Unknown Instance for IpHostConfigData received - ONU doesn't support ME - fill macAddress with zeros",
- log.Fields{"device-id": oo.deviceID, "data-fields": msgObj})
- oo.macAddress = cEmptyMacAddrString
- // trigger retrieval of mib template
- _ = oo.pMibUploadFsm.pFsm.Event(ulEvGetMibTemplate)
- return nil
- default:
- logger.Debugf("MibSync FSM - Unknown Instance in GetResponse Data for %s", log.Fields{"device-id": oo.deviceID, "data-fields": msgObj}, meInstance)
- }
- }
} else {
- logger.Errorw("mibSync FSM - Omci GetResponse Error", log.Fields{"Error": msgObj.Result, "device-id": oo.deviceID})
- err = fmt.Errorf("mibSync FSM - Omci GetResponse Error: %s", oo.deviceID)
+ if err = oo.handleOmciGetResponseErrors(msgObj); err == nil {
+ return nil
+ }
}
logger.Info("MibSync Msg", log.Fields{"Stopped handling of MibSyncChan for device-id": oo.deviceID})
_ = oo.pMibUploadFsm.pFsm.Event(ulEvStop)
@@ -496,6 +480,34 @@
}
}
+func (oo *OnuDeviceEntry) handleOmciGetResponseErrors(msgObj *omci.GetResponse) error {
+ var err error = nil
+ logger.Debugf("MibSync FSM - erroneous result in GetResponse Data: %s", log.Fields{"device-id": oo.deviceID, "data-fields": msgObj}, msgObj.Result)
+ // Up to now the following erroneous results have been seen for different ONU-types to indicate an unsupported ME
+ if msgObj.Result == me.UnknownInstance || msgObj.Result == me.UnknownEntity || msgObj.Result == me.ProcessingError || msgObj.Result == me.NotSupported {
+ entityID := oo.PDevOmciCC.pLastTxMeInstance.GetEntityID()
+ if msgObj.EntityClass == oo.PDevOmciCC.pLastTxMeInstance.GetClassID() && msgObj.EntityInstance == entityID {
+ meInstance := oo.PDevOmciCC.pLastTxMeInstance.GetName()
+ switch meInstance {
+ case "IpHostConfigData":
+ logger.Debugw("MibSync FSM - erroneous result for IpHostConfigData received - ONU doesn't support ME - fill macAddress with zeros",
+ log.Fields{"device-id": oo.deviceID, "data-fields": msgObj})
+ oo.macAddress = cEmptyMacAddrString
+ // trigger retrieval of mib template
+ _ = oo.pMibUploadFsm.pFsm.Event(ulEvGetMibTemplate)
+ return nil
+ default:
+ logger.Warnf("MibSync FSM - erroneous result for %s received - no exceptional treatment defined", log.Fields{"device-id": oo.deviceID, "data-fields": msgObj}, meInstance)
+ err = fmt.Errorf("erroneous result for %s received - no exceptional treatment defined: %s", meInstance, oo.deviceID)
+ }
+ }
+ } else {
+ logger.Errorf("MibSync FSM - erroneous result in GetResponse Data: %s", log.Fields{"device-id": oo.deviceID, "data-fields": msgObj}, msgObj.Result)
+ err = fmt.Errorf("erroneous result in GetResponse Data: %s - %s", msgObj.Result, oo.deviceID)
+ }
+ return err
+}
+
func isSupportedClassID(meClassID me.ClassID) bool {
for _, v := range supportedClassIds {
if v == meClassID {
diff --git a/internal/pkg/onuadaptercore/omci_ani_config.go b/internal/pkg/onuadaptercore/omci_ani_config.go
index 4d46157..7341ff6 100644
--- a/internal/pkg/onuadaptercore/omci_ani_config.go
+++ b/internal/pkg/onuadaptercore/omci_ani_config.go
@@ -176,7 +176,7 @@
return nil
}
- logger.Infow("uniPonAniConfigFsm created", log.Fields{"device-id": instFsm.deviceID})
+ logger.Debugw("uniPonAniConfigFsm created", log.Fields{"device-id": instFsm.deviceID})
return instFsm
}
diff --git a/internal/pkg/onuadaptercore/omci_cc.go b/internal/pkg/onuadaptercore/omci_cc.go
index 33560d9..32d729e 100644
--- a/internal/pkg/onuadaptercore/omci_cc.go
+++ b/internal/pkg/onuadaptercore/omci_cc.go
@@ -115,7 +115,7 @@
func newOmciCC(ctx context.Context, onuDeviceEntry *OnuDeviceEntry,
deviceID string, deviceHandler *deviceHandler,
coreProxy adapterif.CoreProxy, adapterProxy adapterif.AdapterProxy) *omciCC {
- logger.Infow("init-omciCC", log.Fields{"device-id": deviceID})
+ logger.Debugw("init-omciCC", log.Fields{"device-id": deviceID})
var omciCC omciCC
omciCC.enabled = false
omciCC.pOnuDeviceEntry = onuDeviceEntry
diff --git a/internal/pkg/onuadaptercore/omci_vlan_config.go b/internal/pkg/onuadaptercore/omci_vlan_config.go
index 561212c..71c1a8f 100644
--- a/internal/pkg/onuadaptercore/omci_vlan_config.go
+++ b/internal/pkg/onuadaptercore/omci_vlan_config.go
@@ -233,7 +233,7 @@
_ = instFsm.initUniFlowParams(aTechProfileID, aCookieSlice, aMatchVlan, aSetVlan, aSetPcp)
- logger.Infow("UniVlanConfigFsm created", log.Fields{"device-id": instFsm.deviceID,
+ logger.Debugw("UniVlanConfigFsm created", log.Fields{"device-id": instFsm.deviceID,
"accIncrEvto": instFsm.acceptIncrementalEvtoOption})
return instFsm
}
diff --git a/internal/pkg/onuadaptercore/onu_device_entry.go b/internal/pkg/onuadaptercore/onu_device_entry.go
index 5217784..7cd20e5 100644
--- a/internal/pkg/onuadaptercore/onu_device_entry.go
+++ b/internal/pkg/onuadaptercore/onu_device_entry.go
@@ -260,7 +260,7 @@
//newOnuDeviceEntry returns a new instance of a OnuDeviceEntry
//mib_db (as well as not inluded alarm_db not really used in this code? VERIFY!!)
func newOnuDeviceEntry(ctx context.Context, dh *deviceHandler) *OnuDeviceEntry {
- logger.Infow("init-onuDeviceEntry", log.Fields{"device-id": dh.deviceID})
+ logger.Debugw("init-onuDeviceEntry", log.Fields{"device-id": dh.deviceID})
var onuDeviceEntry OnuDeviceEntry
onuDeviceEntry.deviceID = dh.deviceID
onuDeviceEntry.baseDeviceHandler = dh
@@ -432,7 +432,7 @@
//start starts (logs) the omci agent
func (oo *OnuDeviceEntry) start(ctx context.Context) error {
- logger.Infow("OnuDeviceEntry-starting", log.Fields{"for device-id": oo.deviceID})
+ logger.Debugw("OnuDeviceEntry-starting", log.Fields{"for device-id": oo.deviceID})
if oo.PDevOmciCC == nil {
oo.PDevOmciCC = newOmciCC(ctx, oo, oo.deviceID, oo.baseDeviceHandler,
oo.coreProxy, oo.adapterProxy)
diff --git a/internal/pkg/onuadaptercore/onu_uni_tp.go b/internal/pkg/onuadaptercore/onu_uni_tp.go
index e7a1843..40bbb6b 100644
--- a/internal/pkg/onuadaptercore/onu_uni_tp.go
+++ b/internal/pkg/onuadaptercore/onu_uni_tp.go
@@ -104,7 +104,7 @@
//newOnuUniTechProf returns the instance of a OnuUniTechProf
//(one instance per ONU/deviceHandler for all possible UNI's)
func newOnuUniTechProf(ctx context.Context, aDeviceHandler *deviceHandler) *onuUniTechProf {
- logger.Infow("init-OnuUniTechProf", log.Fields{"device-id": aDeviceHandler.deviceID})
+ logger.Debugw("init-OnuUniTechProf", log.Fields{"device-id": aDeviceHandler.deviceID})
var onuTP onuUniTechProf
onuTP.baseDeviceHandler = aDeviceHandler
onuTP.deviceID = aDeviceHandler.deviceID
diff --git a/internal/pkg/onuadaptercore/openonu.go b/internal/pkg/onuadaptercore/openonu.go
index bbf7c2a..946cdc9 100644
--- a/internal/pkg/onuadaptercore/openonu.go
+++ b/internal/pkg/onuadaptercore/openonu.go
@@ -214,7 +214,7 @@
//Process_inter_adapter_message sends messages to a target device (between adapters)
func (oo *OpenONUAC) Process_inter_adapter_message(msg *ic.InterAdapterMessage) error {
logger.Debugw("Process_inter_adapter_message", log.Fields{"msgId": msg.Header.Id,
- "msgProxyDeviceId": msg.Header.ProxyDeviceId, "msgToDeviceId": msg.Header.ToDeviceId})
+ "msgProxyDeviceId": msg.Header.ProxyDeviceId, "msgToDeviceId": msg.Header.ToDeviceId, "Type": msg.Header.Type})
var waitForDhInstPresent bool
//ToDeviceId should address a DeviceHandler instance
@@ -268,11 +268,11 @@
//Reconcile_device is called once when the adapter needs to re-create device - usually on core restart
func (oo *OpenONUAC) Reconcile_device(device *voltha.Device) error {
if device == nil {
- logger.Warn("voltha-device-is-nil")
+ logger.Warn("reconcile-device-voltha-device-is-nil")
return errors.New("nil-device")
}
ctx := context.Background()
- logger.Infow("Reconcile_device", log.Fields{"device-id": device.Id})
+ logger.Infow("reconcile-device", log.Fields{"device-id": device.Id})
var handler *deviceHandler
if handler = oo.getDeviceHandler(device.Id, false); handler == nil {
handler := newDeviceHandler(oo.coreProxy, oo.adapterProxy, oo.eventProxy, device, oo)
@@ -294,7 +294,7 @@
//Disable_device disables the given device
func (oo *OpenONUAC) Disable_device(device *voltha.Device) error {
- logger.Debugw("Disable_device", log.Fields{"device-id": device.Id})
+ logger.Infow("disable-device", log.Fields{"device-id": device.Id})
if handler := oo.getDeviceHandler(device.Id, false); handler != nil {
go handler.disableDevice(device)
return nil
@@ -305,7 +305,7 @@
//Reenable_device enables the onu device after disable
func (oo *OpenONUAC) Reenable_device(device *voltha.Device) error {
- logger.Debugw("Reenable_device", log.Fields{"device-id": device.Id})
+ logger.Infow("reenable-device", log.Fields{"device-id": device.Id})
if handler := oo.getDeviceHandler(device.Id, false); handler != nil {
go handler.reEnableDevice(device)
return nil
@@ -316,7 +316,7 @@
//Reboot_device reboots the given device
func (oo *OpenONUAC) Reboot_device(device *voltha.Device) error {
- logger.Debugw("Reboot-device", log.Fields{"device-id": device.Id})
+ logger.Infow("reboot-device", log.Fields{"device-id": device.Id})
if handler := oo.getDeviceHandler(device.Id, false); handler != nil {
go handler.rebootDevice(device)
return nil
@@ -332,7 +332,7 @@
// Delete_device deletes the given device
func (oo *OpenONUAC) Delete_device(device *voltha.Device) error {
- logger.Debugw("Delete_device", log.Fields{"device-id": device.Id, "SerialNumber": device.SerialNumber})
+ logger.Infow("delete-device", log.Fields{"device-id": device.Id, "SerialNumber": device.SerialNumber})
if handler := oo.getDeviceHandler(device.Id, false); handler != nil {
err := handler.deleteDevicePersistencyData()
//don't leave any garbage - even in error case
@@ -357,6 +357,7 @@
func (oo *OpenONUAC) Update_flows_incrementally(device *voltha.Device,
flows *openflow_13.FlowChanges, groups *openflow_13.FlowGroupChanges, flowMetadata *voltha.FlowMetadata) error {
+ logger.Infow("update-flows-incrementally", log.Fields{"device-id": device.Id})
//flow config is relayed to handler even if the device might be in some 'inactive' state
// let the handler or related FSM's decide, what to do with the modified flow state info
// at least the flow-remove must be done in respect to internal data, while OMCI activity might not be needed here
diff --git a/internal/pkg/onuadaptercore/uniportadmin.go b/internal/pkg/onuadaptercore/uniportadmin.go
index fee161e..0bc5e65 100644
--- a/internal/pkg/onuadaptercore/uniportadmin.go
+++ b/internal/pkg/onuadaptercore/uniportadmin.go
@@ -153,7 +153,7 @@
return nil
}
- logger.Infow("LockStateFsm created", log.Fields{"device-id": instFsm.deviceID})
+ logger.Debugw("LockStateFsm created", log.Fields{"device-id": instFsm.deviceID})
return instFsm
}
@@ -211,7 +211,7 @@
}
func (oFsm *lockStateFsm) enterSettingUnisState(e *fsm.Event) {
- logger.Infow("LockStateFSM - starting PPTP config loop", log.Fields{
+ logger.Debugw("LockStateFSM - starting PPTP config loop", log.Fields{
"in state": e.FSM.Current(), "device-id": oFsm.deviceID, "LockState": oFsm.adminState})
go oFsm.performUniPortAdminSet()
}
@@ -277,7 +277,7 @@
case TestMsg:
msg, _ := message.Data.(TestMessage)
if msg.TestMessageVal == AbortMessageProcessing {
- logger.Infow("LockStateFsm abort ProcessMsg", log.Fields{"for device-id": oFsm.deviceID})
+ logger.Debugw("LockStateFsm abort ProcessMsg", log.Fields{"for device-id": oFsm.deviceID})
break loop
}
logger.Warnw("LockStateFsm unknown TestMessage", log.Fields{"device-id": oFsm.deviceID, "MessageVal": msg.TestMessageVal})
@@ -289,7 +289,7 @@
"message.Type": message.Type})
}
}
- logger.Infow("End LockStateFsm Msg processing", log.Fields{"device-id": oFsm.deviceID})
+ logger.Debugw("End LockStateFsm Msg processing", log.Fields{"device-id": oFsm.deviceID})
}
func (oFsm *lockStateFsm) handleOmciLockStateMessage(msg OmciMessage) {