[VOL-5547] Optimize INFO logs for periodic and ondemand metrics collection, alarm processing and ONU SW upgrade
Change-Id: Ide2397fead3f6c4e41f792a4c7078c7b03ebff6f
Signed-off-by: bseeniva <balaji.seenivasan@radisys.com>
diff --git a/VERSION b/VERSION
index 3c5ed78..f5245c6 100755
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-2.13.11
+2.13.12
diff --git a/internal/pkg/common/omci_cc.go b/internal/pkg/common/omci_cc.go
index 5984c3d..e336e6a 100755
--- a/internal/pkg/common/omci_cc.go
+++ b/internal/pkg/common/omci_cc.go
@@ -4442,7 +4442,7 @@
omciMsgsPerWindow *ia.OmciMessages, aIsExtendedOmci bool) (OmciTransferStructure, error) {
//onuswsections uses only low prioirity tids
tid := oo.GetOnuSwSecNextTid()
- logger.Infow(ctx, "send DlSectionRequest:", log.Fields{"device-id": oo.deviceID,
+ logger.Debugw(ctx, "send DlSectionRequest:", log.Fields{"device-id": oo.deviceID,
"SequNo": strconv.FormatInt(int64(tid), 16),
"InstId": strconv.FormatInt(int64(aImageMeID), 16), "omci-ack": aAckRequest, "sectionNo": aDownloadSectionNo, "sectionData": aSection})
diff --git a/internal/pkg/core/openonu.go b/internal/pkg/core/openonu.go
index 8d3d1a6..19afb48 100755
--- a/internal/pkg/core/openonu.go
+++ b/internal/pkg/core/openonu.go
@@ -539,7 +539,7 @@
return resp, nil
case *extension.GetValueRequest_OnuAllocGemStats:
resp := handler.getONUGEMStatsInfo(ctx)
- logger.Infow(ctx, "Received response for on demand GEM counters ", log.Fields{"response": resp})
+ logger.Infow(ctx, "Received response for onu Alloc Gem Stats ", log.Fields{"response": resp})
return resp, nil
case *extension.GetValueRequest_FecHistory:
return handler.getOnuFECStats(ctx), nil
@@ -607,7 +607,7 @@
firstDevice = false
vendorID = onuVolthaDevice.VendorId
imageIdentifier = vendorID + imageIdentifier //head on vendor ID of the ONU
- logger.Infow(ctx, "download request for file",
+ logger.Debugw(ctx, "download request for file",
log.Fields{"device-id": loDeviceID, "image-id": imageIdentifier})
// call the StartDownload synchronously to detect 'immediate' download problems
diff --git a/internal/pkg/omcitst/omci_self_test_handler.go b/internal/pkg/omcitst/omci_self_test_handler.go
index 14b70d5..9fe8841 100755
--- a/internal/pkg/omcitst/omci_self_test_handler.go
+++ b/internal/pkg/omcitst/omci_self_test_handler.go
@@ -241,12 +241,12 @@
}
logger.Debugw(ctx, "OMCI test response Data", log.Fields{"device-id": selfTestCb.deviceID, "data-fields": msgObj})
if msgObj.Result == generated.Success && msgObj.EntityClass == classID {
- logger.Infow(ctx, "OMCI test response success", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
+ logger.Debugw(ctx, "OMCI test response success", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
selfTestCb.triggerFsmEvent(cb.fsm, selfTestEventTestResponseSuccess, classID)
return
}
- logger.Infow(ctx, "OMCI test response failure", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
+ logger.Errorw(ctx, "OMCI test response failure", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
selfTestCb.pDevEntry.GetDevOmciCC().ReleaseTid(ctx, msg.OmciMsg.TransactionID)
selfTestCb.triggerFsmEvent(cb.fsm, selfTestEventAbort)
selfTestCb.submitFailureGetValueResponse(ctx, cb.respChan, extension.GetValueResponse_UNSUPPORTED, extension.GetValueResponse_ERROR, cb.reqMsg)
@@ -314,7 +314,7 @@
"laser-bias-current": singleValResp.Response.GetOnuOpticalInfo().LaserBiasCurrent,
"temperature": singleValResp.Response.GetOnuOpticalInfo().Temperature})
selfTestCb.triggerFsmEvent(cb.fsm, selfTestEventTestResultSuccess)
- logger.Infow(ctx, "OMCI test result success - pushing results", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
+ logger.Debugw(ctx, "OMCI test result success - pushing results", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
cb.respChan <- singleValResp
selfTestCb.selfTestRequestComplete(ctx, cb.reqMsg)
logger.Infow(ctx, "OMCI test result success - pushing results complete", log.Fields{"device-id": selfTestCb.deviceID, "classID": classID})
@@ -362,7 +362,7 @@
if err != nil {
return
}
- logger.Infow(ctx, "self test req handling complete", log.Fields{"device-id": selfTestCb.deviceID, "meClassID": meClassID})
+ logger.Debugw(ctx, "self test req handling complete", log.Fields{"device-id": selfTestCb.deviceID, "meClassID": meClassID})
// Clear the fsmCb from the map
delete(selfTestCb.selfTestFsmMap, meClassID)
}
@@ -415,7 +415,7 @@
logger.Errorw(ctx, "self test already in progress for class id", log.Fields{"device-id": selfTestCb.deviceID, "class-id": meClassID})
return fmt.Errorf("self-test-already-in-progress-for-class-id-%v-device-id-%v", meClassID, selfTestCb.deviceID)
}
- logger.Infow(ctx, "self test request initiated", log.Fields{"device-id": selfTestCb.deviceID, "meClassID": meClassID})
+ logger.Debugw(ctx, "self test request initiated", log.Fields{"device-id": selfTestCb.deviceID, "meClassID": meClassID})
// indicates only if the FSM was initiated correctly. Response is asynchronous on respChan.
// If the return from here is NOT nil, the caller shall not wait for async response.
return selfTestCb.initiateNewSelfTestFsm(ctx, reqMsg, CommChan, meClassID, respChan)
diff --git a/internal/pkg/pmmgr/onu_metrics_manager.go b/internal/pkg/pmmgr/onu_metrics_manager.go
index c333ba4..a3a3bf1 100755
--- a/internal/pkg/pmmgr/onu_metrics_manager.go
+++ b/internal/pkg/pmmgr/onu_metrics_manager.go
@@ -4255,7 +4255,7 @@
}
for allocID, gemSlice := range allocIDtoGem {
- logger.Infow(ctx, "AllocID", log.Fields{"alloc-id": allocID})
+ logger.Debugw(ctx, "AllocID", log.Fields{"alloc-id": allocID})
allocIdGemData := extension.OnuAllocGemHistoryData{
OnuAllocIdInfo: &extension.OnuAllocHistoryData{},
GemPortInfo: []*extension.OnuGemPortHistoryData{},
diff --git a/internal/pkg/swupg/file_download_manager.go b/internal/pkg/swupg/file_download_manager.go
index bb9bd69..d39eb18 100755
--- a/internal/pkg/swupg/file_download_manager.go
+++ b/internal/pkg/swupg/file_download_manager.go
@@ -101,7 +101,7 @@
// StartDownload returns FileState and error code from download request for the given file name and URL
func (dm *FileDownloadManager) StartDownload(ctx context.Context, aImageName string, aURLCommand string) (FileState, error) {
logger.Infow(ctx, "image download-to-adapter requested", log.Fields{
- "image-name": aImageName, "url-command": aURLCommand})
+ "image-name": aImageName, "url-command": aURLCommand, "local-path": cDefaultLocalDir})
// keep a semaphore over the complete method in order to avoid parallel entrance to this method
// otherwise a temporary file state 'Started' could be indicated allowing start of ONU upgrade handling
@@ -326,7 +326,7 @@
// downloadFile downloads the specified file from the given http location
func (dm *FileDownloadManager) downloadFile(ctx context.Context, aURLCommand string, aFilePath string, aFileName string) error {
// Get the data
- logger.Infow(ctx, "downloading with URL", log.Fields{"url": aURLCommand, "localPath": aFilePath})
+ logger.Debugw(ctx, "downloading with URL", log.Fields{"url": aURLCommand, "localPath": aFilePath})
// verifying the complete URL by parsing it to its URL elements
urlBase, err1 := url.Parse(aURLCommand)
if err1 != nil {
@@ -435,7 +435,7 @@
return
}
fileSize := fileStats.Size()
- logger.Infow(ctx, "written file size is", log.Fields{"file": aLocalPathName, "length": fileSize})
+ logger.Debugw(ctx, "written file size is", log.Fields{"file": aLocalPathName, "length": fileSize})
dm.updateFileState(ctx, aFileName, fileSize)
//TODO:!!! further extension could be provided here, e.g. already computing and possibly comparing the CRC, vendor check
diff --git a/internal/pkg/swupg/omci_onu_upgrade.go b/internal/pkg/swupg/omci_onu_upgrade.go
index 3cce167..fff4b51 100755
--- a/internal/pkg/swupg/omci_onu_upgrade.go
+++ b/internal/pkg/swupg/omci_onu_upgrade.go
@@ -715,7 +715,7 @@
}
oFsm.origImageLength = uint32(fileLen)
oFsm.imageLength = uint32(len(oFsm.imageBuffer))
- logger.Infow(ctx, "OnuUpgradeFsm starts with StartSwDl values", log.Fields{
+ logger.Debugw(ctx, "OnuUpgradeFsm starts with StartSwDl values", log.Fields{
"MeId": oFsm.InactiveImageMeID, "windowSizeLimit": oFsm.omciDownloadWindowSizeLimit,
"ImageSize": oFsm.imageLength, "original file size": fileLen})
//"NumberOfCircuitPacks": oFsm.numberCircuitPacks, "CircuitPacks MeId": 0}) //parallel circuit packs download not supported
@@ -826,7 +826,7 @@
windowAckRequest = 1
oFsm.omciDownloadWindowSizeLast = oFsm.nextDownloadSectionsWindow
- logger.Infow(ctx, "DlSection expect Response for last window (section)", log.Fields{
+ logger.Debugw(ctx, "DlSection expect Response for last window (section)", log.Fields{
"device-id": oFsm.deviceID, "DlSectionNoAbsolute": oFsm.nextDownloadSectionsAbsolute})
}
oFsm.mutexUpgradeParams.Unlock() //unlock here to give other functions some chance to process during/after the send request
@@ -883,7 +883,7 @@
//nolint:unparam
func (oFsm *OnuUpgradeFsm) enterFinalizeDL(ctx context.Context, e *fsm.Event) {
- logger.Infow(ctx, "OnuUpgradeFsm finalize DL", log.Fields{
+ logger.Debugw(ctx, "OnuUpgradeFsm finalize DL", log.Fields{
"device-id": oFsm.deviceID, "crc": strconv.FormatInt(int64(oFsm.imageCRC), 16), "delay": oFsm.delayEndSwDl})
//use a background routine to wait EndSwDlDelay and then send the EndSwDl request
// in order to avoid blocking on synchronous event calls for the complete wait time
@@ -943,7 +943,7 @@
//nolint:unparam
func (oFsm *OnuUpgradeFsm) enterWaitEndDL(ctx context.Context, e *fsm.Event) {
- logger.Infow(ctx, "OnuUpgradeFsm WaitEndDl", log.Fields{
+ logger.Debugw(ctx, "OnuUpgradeFsm WaitEndDl", log.Fields{
"device-id": oFsm.deviceID, "wait delay": oFsm.waitDelayEndSwDl * time.Second, "wait count": oFsm.waitCountEndSwDl})
if oFsm.waitCountEndSwDl == 0 {
logger.Errorw(ctx, "WaitEndDl abort: max limit of EndSwDL reached", log.Fields{
@@ -1522,7 +1522,7 @@
oFsm.mutexUpgradeParams.Lock()
if msgObj.EntityInstance == oFsm.InactiveImageMeID {
sectionNumber := msgObj.SectionNumber
- logger.Infow(ctx, "DlSectionResponse received", log.Fields{
+ logger.Debugw(ctx, "DlSectionResponse received", log.Fields{
"window section-number": sectionNumber, "window": oFsm.nextDownloadWindow, "device-id": oFsm.deviceID})
oFsm.nextDownloadWindow++
@@ -1811,7 +1811,7 @@
} else {
//have to wait on explicit activation request
oFsm.mutexUpgradeParams.Unlock()
- logger.Infow(ctx, "OnuUpgradeFsm - expected ONU image version indicated by the ONU, wait for activate request",
+ logger.Debugw(ctx, "OnuUpgradeFsm - expected ONU image version indicated by the ONU, wait for activate request",
log.Fields{"device-id": oFsm.deviceID})
_ = oFsm.PAdaptFsm.PFsm.Event(UpgradeEvWaitForActivate)
}