[VOL-3833] OnuKVStoreMutex is held for a long period of time
Change-Id: Ifaaba02bef33a6c7699f5ac54770ba2a24044cda
diff --git a/VERSION b/VERSION
index 0495c4a..4de2ee6 100755
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-1.2.3
+1.2.4-dev162
diff --git a/internal/pkg/onuadaptercore/device_handler.go b/internal/pkg/onuadaptercore/device_handler.go
index 7d2d226..3e20883 100644
--- a/internal/pkg/onuadaptercore/device_handler.go
+++ b/internal/pkg/onuadaptercore/device_handler.go
@@ -364,8 +364,6 @@
// to possible concurrent access by flow processing
dh.pOnuTP.lockTpProcMutex()
defer dh.pOnuTP.unlockTpProcMutex()
- pDevEntry.lockOnuKVStoreMutex()
- defer pDevEntry.unlockOnuKVStoreMutex()
if techProfMsg.UniId > 255 {
return fmt.Errorf(fmt.Sprintf("received UniId value exceeds range: %d, device-id: %s",
@@ -436,8 +434,6 @@
//compare TECH_PROFILE_DOWNLOAD_REQUEST
dh.pOnuTP.lockTpProcMutex()
defer dh.pOnuTP.unlockTpProcMutex()
- pDevEntry.lockOnuKVStoreMutex()
- defer pDevEntry.unlockOnuKVStoreMutex()
if delGemPortMsg.UniId > 255 {
return fmt.Errorf(fmt.Sprintf("received UniId value exceeds range: %d, device-id: %s",
@@ -496,8 +492,6 @@
//compare TECH_PROFILE_DOWNLOAD_REQUEST
dh.pOnuTP.lockTpProcMutex()
defer dh.pOnuTP.unlockTpProcMutex()
- pDevEntry.lockOnuKVStoreMutex()
- defer pDevEntry.unlockOnuKVStoreMutex()
if delTcontMsg.UniId > 255 {
return fmt.Errorf(fmt.Sprintf("received UniId value exceeds range: %d, device-id: %s",
@@ -795,6 +789,8 @@
}
dh.pOnuTP.lockTpProcMutex()
defer dh.pOnuTP.unlockTpProcMutex()
+ pDevEntry.persUniConfigMutex.RLock()
+ defer pDevEntry.persUniConfigMutex.RUnlock()
if len(pDevEntry.sOnuPersistentData.PersUniConfig) == 0 {
logger.Debugw(ctx, "reconciling - no uni-configs have been stored before adapter restart - terminate reconcilement",
@@ -841,6 +837,9 @@
logger.Errorw(ctx, "No valid OnuDevice - aborting", log.Fields{"device-id": dh.deviceID})
return
}
+ pDevEntry.persUniConfigMutex.RLock()
+ defer pDevEntry.persUniConfigMutex.RUnlock()
+
if len(pDevEntry.sOnuPersistentData.PersUniConfig) == 0 {
logger.Debugw(ctx, "reconciling - no uni-configs have been stored before adapter restart - terminate reconcilement",
log.Fields{"device-id": dh.deviceID})
@@ -903,8 +902,6 @@
logger.Debugw(ctx, "OnuDevice does not exist - nothing to delete", log.Fields{"device-id": dh.deviceID})
return nil
}
- pDevEntry.lockOnuKVStoreMutex()
- defer pDevEntry.unlockOnuKVStoreMutex()
// deadline context to ensure completion of background routines waited for
//20200721: 10s proved to be less in 8*8 ONU test on local vbox machine with debug, might be further adapted
@@ -2505,9 +2502,6 @@
}
pDevEntry.updateOnuUniFlowConfig(aUniID, aUniVlanFlowParams)
- pDevEntry.lockOnuKVStoreMutex()
- defer pDevEntry.unlockOnuKVStoreMutex()
-
// deadline context to ensure completion of background routines waited for
//20200721: 10s proved to be less in 8*8 ONU test on local vbox machine with debug, might be further adapted
deadline := time.Now().Add(dh.pOpenOnuAc.maxTimeoutInterAdapterComm) //allowed run time to finish before execution
@@ -2553,9 +2547,6 @@
logger.Warnw(ctx, "No valid OnuDevice", log.Fields{"device-id": dh.deviceID})
return fmt.Errorf("no valid OnuDevice: %s", dh.deviceID)
}
- pDevEntry.lockOnuKVStoreMutex()
- defer pDevEntry.unlockOnuKVStoreMutex()
-
deadline := time.Now().Add(dh.pOpenOnuAc.maxTimeoutInterAdapterComm) //allowed run time to finish before execution
dctx, cancel := context.WithDeadline(context.Background(), deadline)
diff --git a/internal/pkg/onuadaptercore/onu_device_entry.go b/internal/pkg/onuadaptercore/onu_device_entry.go
index b65b055..a9b34cd 100644
--- a/internal/pkg/onuadaptercore/onu_device_entry.go
+++ b/internal/pkg/onuadaptercore/onu_device_entry.go
@@ -238,6 +238,7 @@
PDevOmciCC *omciCC
pOnuDB *onuDeviceDB
mibTemplateKVStore *db.Backend
+ persUniConfigMutex sync.RWMutex
sOnuPersistentData onuPersistentData
mibTemplatePath string
onuKVStoreMutex sync.RWMutex
@@ -562,8 +563,12 @@
logger.Debugw(ctx, "onuKVStore not set - abort", log.Fields{"device-id": oo.deviceID})
return fmt.Errorf(fmt.Sprintf("onuKVStore-not-set-abort-%s", oo.deviceID))
}
+ oo.persUniConfigMutex.Lock()
+ defer oo.persUniConfigMutex.Unlock()
oo.sOnuPersistentData = onuPersistentData{0, 0, "", "", "", false, false, oo.mibAuditInterval, 0, 0, make([]uniPersConfig, 0)}
+ oo.onuKVStoreMutex.RLock()
Value, err := oo.onuKVStore.Get(ctx, oo.onuKVStorePath)
+ oo.onuKVStoreMutex.RUnlock()
if err == nil {
if Value != nil {
logger.Debugw(ctx, "ONU-data read",
@@ -608,11 +613,17 @@
func (oo *OnuDeviceEntry) deletePersistentData(ctx context.Context, aProcessingStep uint8) {
logger.Debugw(ctx, "delete and clear internal persistency data", log.Fields{"device-id": oo.deviceID})
+
+ oo.persUniConfigMutex.Lock()
+ defer oo.persUniConfigMutex.Unlock()
+
oo.sOnuPersistentData.PersUniConfig = nil //releasing all UniConfig entries to garbage collector
oo.sOnuPersistentData = onuPersistentData{0, 0, "", "", "", false, false, oo.mibAuditInterval, 0, 0, make([]uniPersConfig, 0)} //default entry
logger.Debugw(ctx, "delete ONU-data from KVStore", log.Fields{"device-id": oo.deviceID})
+ oo.onuKVStoreMutex.Lock()
err := oo.onuKVStore.Delete(ctx, oo.onuKVStorePath)
+ oo.onuKVStoreMutex.Unlock()
if err != nil {
logger.Errorw(ctx, "unable to delete in KVstore", log.Fields{"device-id": oo.deviceID, "err": err})
oo.chOnuKvProcessingStep <- 0 //error indication
@@ -648,6 +659,9 @@
//TODO: verify usage of these values during restart UC
oo.sOnuPersistentData.PersAdminState = oo.baseDeviceHandler.pOnuIndication.AdminState
oo.sOnuPersistentData.PersOperState = oo.baseDeviceHandler.pOnuIndication.OperState
+
+ oo.persUniConfigMutex.RLock()
+ defer oo.persUniConfigMutex.RUnlock()
logger.Debugw(ctx, "Update ONU-data in KVStore", log.Fields{"device-id": oo.deviceID, "sOnuPersistentData": oo.sOnuPersistentData})
Value, err := json.Marshal(oo.sOnuPersistentData)
@@ -657,7 +671,9 @@
oo.chOnuKvProcessingStep <- 0 //error indication
return
}
+ oo.onuKVStoreMutex.Lock()
err = oo.onuKVStore.Put(ctx, oo.onuKVStorePath, Value)
+ oo.onuKVStoreMutex.Unlock()
if err != nil {
logger.Errorw(ctx, "unable to write ONU-data into KVstore", log.Fields{"device-id": oo.deviceID, "err": err})
oo.chOnuKvProcessingStep <- 0 //error indication
@@ -671,6 +687,9 @@
as also the complete sequence is ensured to 'run to completion' before some new request is accepted
no specific concurrency protection to sOnuPersistentData is required here
*/
+ oo.persUniConfigMutex.Lock()
+ defer oo.persUniConfigMutex.Unlock()
+
for k, v := range oo.sOnuPersistentData.PersUniConfig {
if v.PersUniID == aUniID {
logger.Debugw(ctx, "PersUniConfig-entry already exists", log.Fields{"device-id": oo.deviceID, "uniID": aUniID})
@@ -738,6 +757,9 @@
func (oo *OnuDeviceEntry) updateOnuUniFlowConfig(aUniID uint8, aUniVlanFlowParams *[]uniVlanFlowParams) {
+ oo.persUniConfigMutex.Lock()
+ defer oo.persUniConfigMutex.Unlock()
+
for k, v := range oo.sOnuPersistentData.PersUniConfig {
if v.PersUniID == aUniID {
oo.sOnuPersistentData.PersUniConfig[k].PersFlowParams = make([]uniVlanFlowParams, len(*aUniVlanFlowParams))
@@ -776,15 +798,6 @@
func (oo *OnuDeviceEntry) getKvProcessingErrorIndication() error {
return oo.onuKVStoreprocResult
}
-
-func (oo *OnuDeviceEntry) lockOnuKVStoreMutex() {
- oo.onuKVStoreMutex.Lock()
-}
-
-func (oo *OnuDeviceEntry) unlockOnuKVStoreMutex() {
- oo.onuKVStoreMutex.Unlock()
-}
-
func (oo *OnuDeviceEntry) incrementMibDataSync(ctx context.Context) {
if oo.sOnuPersistentData.PersMibDataSyncAdpt < 255 {
oo.sOnuPersistentData.PersMibDataSyncAdpt++