Page Comparison

References:

Jira Legacy

server	System Jira
columnIds	issuekey,summary,issuetype,created,updated,duedate,assignee,reporter,priority,status,resolution
columns	key,summary,type,created,updated,due,assignee,reporter,priority,status,resolution
serverId	4733707d-2057-3a0f-ae5e-4fd8aff50176
key	CPS-1126

Overview :

With previous versions we were able to register 10k cmhandles (in 4 threads) in 12 minutes.
With the current CPS master we sent the 10k cmHandles around 10 minutes to NCMP, so it is not faster than before. What I see is that NCMP starts getting modules in a background thread (seems to be one thread) and handling one cmhandle takes more seconds.
Currenlty in 12 minutes only 150 cmHandles got available with ready state in NCMP, because getting modules and changing the state is quite slow this way.

...

Analyzed the logs the summary is as below :

Patch used for testing :

https://gerrit.onap.org/r/c/cps/+/129829/5//COMMIT_MSG

Configurations:

...

1

...

100

...

Fixed Delay String (in ms)

...

timers:
    advised-modules-sync:
        sleep-time-ms:

...

30000

...

timers:
    locked-modules-sync:
        sleep-time-ms:

...

timers:
   cm-handle-data-sync:
       sleep-time-ms:

...

Enabled ?

...

data-sync:
    cache:
        enabled:

...

false

Scenario 1: If there is no cm handle into Advised state

Average time elapsed to get/fetch cm handles by state ADVISED is ~ 3-4 ms

CPS -log :

2022-07-15 04:40:17.918  INFO [cps-application,57eae02b31a98818,57eae02b31a98818] 1 --- [  watchdog-th-9] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to get cm handles by state ADVISED is : 3 ms | Fetched data node size is 0
2022-07-15 04:40:17.918  INFO [cps-application,57eae02b31a98818,57eae02b31a98818] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : No Cm-Handles currently found in an ADVISED state
2022-07-15 04:40:48.003  INFO [cps-application,e1fb65c00a949ce0,e1fb65c00a949ce0] 1 --- [  watchdog-th-9] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to get cm handles by state ADVISED is : 4 ms | Fetched data node size is 0
2022-07-15 04:40:48.003  INFO [cps-application,e1fb65c00a949ce0,e1fb65c00a949ce0] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : No Cm-Handles currently found in an ADVISED state

Scenario 2: If we started registering 1458 with configuration mentioned above :

...

Average Time elapsed (in ~ ms)

...

Get / fetch cm handles by state ADVISED

...

19404

...

Time

...

Registration of 1458 cm handles started

...

04:41:00

...

Average time to make all 1458 cm handles from ADVICED to READY state is: ~ 10 minutes

First Batch:

First iteration:

2022-07-15 04:41:37.407  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to get cm handles by state ADVISED is : 19404 ms | Fetched data node size is 601
2022-07-15 04:41:37.408  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to shuffle  advisedCmHandles list of size : 601 is 0 ms
2022-07-15 04:42:40.516  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to get yang model cm handles is : 63107 ms
2022-07-15 04:42:40.600  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to get cm handle state with id 6D3F803EFCCB92F84FEE3CAEEEC0C48D is : 83 ms
2022-07-15 04:42:40.618  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to deleteSchemaSetIfExists with id 6D3F803EFCCB92F84FEE3CAEEEC0C48D is : 17 ms
2022-07-15 04:43:19.011  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to syncAndCreateSchemaSetAndAnchor with id 6D3F803EFCCB92F84FEE3CAEEEC0C48D is : 38393 ms
2022-07-15 04:43:19.307  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to executeAdvisedCmHandlePoll saveCmHandleState with id 6D3F803EFCCB92F84FEE3CAEEEC0C48D is : 293 ms
2022-07-15 04:43:19.307  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : 6D3F803EFCCB92F84FEE3CAEEEC0C48D is now in READY state

Second iteration :

2022-07-15 04:43:19.314  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to get cm handle state with id CA29889D3AE24486DD95344AEC60E0F7 is : 7 ms
2022-07-15 04:43:19.317  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to deleteSchemaSetIfExists with id CA29889D3AE24486DD95344AEC60E0F7 is : 2 ms
2022-07-15 04:43:19.916  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to syncAndCreateSchemaSetAndAnchor with id CA29889D3AE24486DD95344AEC60E0F7 is : 599 ms
2022-07-15 04:43:20.001  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to executeAdvisedCmHandlePoll saveCmHandleState with id CA29889D3AE24486DD95344AEC60E0F7 is : 84 ms
2022-07-15 04:43:20.001  INFO [cps-application,8ffa50adfe3fb407,8ffa50adfe3fb407] 1 --- [  watchdog-th-9] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : CA29889D3AE24486DD95344AEC60E0F7 is now in READY state

Second Batch:

First iteration:

2022-07-15 04:45:51.513  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to get cm handles by state ADVISED is : 3485 ms | Fetched data node size is 857
2022-07-15 04:45:51.513  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to shuffle  advisedCmHandles list of size : 857 is 0 ms
2022-07-15 04:46:28.851  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.ncmp.api.inventory.sync.SyncUtils  : Time elapsed to get yang model cm handles is : 37337 ms
2022-07-15 04:46:28.861  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to get cm handle state with id F11218269B0D31012FBAFF88F9B4A345 is : 10 ms
2022-07-15 04:46:28.864  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to deleteSchemaSetIfExists with id F11218269B0D31012FBAFF88F9B4A345 is : 2 ms
2022-07-15 04:46:29.101  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to syncAndCreateSchemaSetAndAnchor with id F11218269B0D31012FBAFF88F9B4A345 is : 237 ms
2022-07-15 04:46:29.116  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to executeAdvisedCmHandlePoll saveCmHandleState with id F11218269B0D31012FBAFF88F9B4A345 is : 14 ms
2022-07-15 04:46:29.116  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : F11218269B0D31012FBAFF88F9B4A345 is now in READY state

Second iteration:

2022-07-15 04:46:29.128  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to get cm handle state with id D79ADF6E3AE62A2D450BEB0F14565EE1 is : 12 ms
2022-07-15 04:46:29.131  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to deleteSchemaSetIfExists with id D79ADF6E3AE62A2D450BEB0F14565EE1 is : 2 ms
2022-07-15 04:46:29.254  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to syncAndCreateSchemaSetAndAnchor with id D79ADF6E3AE62A2D450BEB0F14565EE1 is : 122 ms
2022-07-15 04:46:29.262  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : Time elapsed to executeAdvisedCmHandlePoll saveCmHandleState with id D79ADF6E3AE62A2D450BEB0F14565EE1 is : 8 ms
2022-07-15 04:46:29.262  INFO [cps-application,acf4595802b71109,acf4595802b71109] 1 --- [ watchdog-th-10] o.o.c.n.a.i.sync.ModuleSyncWatchdog      : D79ADF6E3AE62A2D450BEB0F14565EE1 is now in READY state

As we suspected if there is any issue when creating new yang resources from dmi :

Csaba performed testing as before on patchset6 and we have summary as below :

Search "Time elapsed to getNewYangResourcesFromDmi" (9 hits in 1 file of 1 searched)
new 174 (9 hits)

Average Time elapsed to getNewYangResourcesFromDmi is : (276+79+106+131+186+8+109+6+5/9)= ~100.66 ms

Line 35: 2022-07-19 15:21:19.543 INFO [cps-application,26a4e77759bbed32,26a4e77759bbed32] 1 --- [ watchdog-th-7] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 276 ms for YangModelCmHandle is : YangModelCmHandle(id=872D4BE15DAB25EEEBC183B2EAF2014C, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:20:01.345+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,MeContext=B07MSRBS-V202), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=B07MSRBS-V202), YangModelCmHandle.Property(name=ossModelIdentity, value=22.Q1-R48A08), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=nodeModelIdentity, value=22.Q1-R48A08), YangModelCmHandle.Property(name=subSystem, value=7)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-ResEquipmentSupportFunction, revision=3350-03-27, namespace=), ModuleReference(moduleName=ericsson-enm-ReqFwSlot, revision=5678-01-29, namespace=), ModuleReference(moduleName=ericsson-enm-RmePimCancellationFunction, revision=7705-05-22, namespace=), ModuleReference(moduleName=ericsson-enm-RtnMacSecProfile, revision=7705-05-22, namespace=), ModuleReference(moduleName=ericsson-enm-RtnQoSSystem, revision=8656-03-19, namespace=), ModuleReference(moduleName=ericsson-enm-RmeAI, revision=7709-08-11, namespace=), ModuleReference(moduleName=ericsson-enm-RtnRoutesStaticRouteIPv6, revision=3817-04-07, namespace=), ModuleReference(moduleName=ericsson-enm-Lrat, revision=6585-01-11, namespace=), ModuleReference(moduleName=ericsson-enm-RcsPMEventM, revision=7709-08-11, namespa ... Line 71: 2022-07-19 15:21:25.641 INFO [cps-application,26a4e77759bbed32,26a4e77759bbed32] 1 --- [ watchdog-th-7] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 79 ms for YangModelCmHandle is : YangModelCmHandle(id=9475946118AC034DFCC7B84B8C8D0D0D, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:19:58.751+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=ossModelIdentity, value=21.Q4-R41A14), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,MeContext=B33MSRBS-V202), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=nodeModelIdentity, value=21.Q4-R41A14), YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=B33MSRBS-V202)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-ReqORadio, revision=3811-03-30, namespace=), ModuleReference(moduleName=ericsson-enm-ReqRfPort, revision=3745-06-20, namespace=), ModuleReference(moduleName=ericsson-enm-RtnMacSecCa, revision=5678-01-29, namespace=), ModuleReference(moduleName=ericsson-enm-RcsLM, revision=4906-05-09, namespace=), ModuleReference(moduleName=ericsson-enm-RtnMacSecProfile, revision=5678-01-29, namespace=), ModuleReference(moduleName=ericsson-enm-RmeSectorEquipmentFunction, revision=9747-02-08, namespace=), ModuleReference(moduleName=ericsson-enm-RtnSctpProfile, revision=5062-08-08, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL3InterfaceIPv6, revision=8656-03-19, namespace=), ModuleReference(moduleName=ericsson-enm-GNBCUUP, revision=9366-05-02, namespace=), ModuleReferenc ... Line 147: 2022-07-19 15:21:34.253 INFO [cps-application,26a4e77759bbed32,26a4e77759bbed32] 1 --- [ watchdog-th-7] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 106 ms for YangModelCmHandle is : YangModelCmHandle(id=FF0C68EC64A66E552DA5E6E6FEBC1010, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:19:52.655+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=B49MSRBS-V201), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,MeContext=B49MSRBS-V201), YangModelCmHandle.Property(name=ossModelIdentity, value=22.Q1-R44A45), YangModelCmHandle.Property(name=nodeModelIdentity, value=22.Q1-R44A45), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-Lrat, revision=9355-11-20, namespace=), ModuleReference(moduleName=ericsson-enm-ReqAntennaSystem, revision=7214-12-23, namespace=), ModuleReference(moduleName=ericsson-enm-GNBDU, revision=9070-04-24, namespace=), ModuleReference(moduleName=ericsson-enm-GNBCUUP, revision=7419-04-06, namespace=), ModuleReference(moduleName=ericsson-enm-GNBCUCP, revision=2167-05-05, namespace=)] Line 489: 2022-07-19 15:22:01.196 INFO [cps-application,26a4e77759bbed32,26a4e77759bbed32] 1 --- [ watchdog-th-7] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 131 ms for YangModelCmHandle is : YangModelCmHandle(id=C8A2F61654A98ACE395D30F267529CA9, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:19:51.042+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=nodeModelIdentity, value=21.Q2-R29A13), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,MeContext=B40MSRBS-V201), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=ossModelIdentity, value=21.Q2-R29A13), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=B40MSRBS-V201)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-GNBDU, revision=5057-01-13, namespace=), ModuleReference(moduleName=ericsson-enm-ComTop, revision=5098-01-14, namespace=), ModuleReference(moduleName=ericsson-enm-ReqAasData, revision=7705-05-22, namespace=), ModuleReference(moduleName=ericsson-enm-Lrat, revision=6041-07-08, namespace=), ModuleReference(moduleName=ericsson-enm-ReqRiLink, revision=2496-02-28, namespace=), ModuleReference(moduleName=ericsson-enm-RtnIkev2PolicyProfile, revision=3739-02-21, namespace=), ModuleReference(moduleName=ericsson-enm-RsyncSynchronization, revision=3737-05-03, namespace=), ModuleReference(moduleName=ericsson-enm-LratRpUpt, revision=3731-01-03, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL3Router, revision=8914-12-10, namespace=), ModuleReference(moduleName=ericss ... Line 1101: 2022-07-19 15:24:39.088 INFO [cps-application,ef4137071817ed67,ef4137071817ed67] 1 --- [ watchdog-th-5] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 186 ms for YangModelCmHandle is : YangModelCmHandle(id=156E680ADEE8FD195CEF82AA32F42D6E, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:20:42.146+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=LTE15dg2ERBS00065), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,SubNetwork=NETSimW), YangModelCmHandle.Property(name=ossModelIdentity, value=21.Q3-R37A02), YangModelCmHandle.Property(name=nodeModelIdentity, value=21.Q3-R37A02), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=subSystem, value=7)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-RtnL3InterfaceIPv4, revision=2195-08-17, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL3InterfaceIPv6, revision=2576-05-25, namespace=), ModuleReference(moduleName=ericsson-enm-RtnPBRIPv6, revision=5680-03-10, namespace=), ModuleReference(moduleName=ericsson-enm-RsyncRadioEquipmentClock, revision=9432-02-29, namespace=), ModuleReference(moduleName=ericsson-enm-RtnSctp, revision=7744-01-07, namespace=), ModuleReference(moduleName=ericsson-enm-ReqFieldReplaceableUnit, revision=4671-02-12, namespace=), ModuleReference(moduleName=ericsson-enm-ReqAntennaSystem, revision=5107-06-08, namespace=), ModuleReference(moduleName=ericsson-enm-GNBCUUP, revision=8925-03-19, namespace=), ModuleReference(moduleName=ericsson-enm-ReqAdb, revision=9732-09-12, namespace=), ... Line 1267: 2022-07-19 15:24:44.665 INFO [cps-application,ef4137071817ed67,ef4137071817ed67] 1 --- [ watchdog-th-5] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 8 ms for YangModelCmHandle is : YangModelCmHandle(id=094A3BECE8081998C04BA4696F1C296D, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:20:56.947+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=ossModelIdentity, value=19.Q3-R44A20), YangModelCmHandle.Property(name=nodeModelIdentity, value=19.Q3-R44A20), YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,SubNetwork=NETSimW), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=LTE26dg2ERBS00002)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-RtnLldp, revision=9732-09-12, namespace=), ModuleReference(moduleName=ericsson-enm-ReqDiPort, revision=9732-09-12, namespace=), ModuleReference(moduleName=ericsson-enm-ReqDiLink, revision=7705-05-22, namespace=), ModuleReference(moduleName=ericsson-enm-ResExternalPower, revision=5678-01-29, namespace=), ModuleReference(moduleName=ericsson-enm-ReqTransceiver, revision=3731-01-03, namespace=), ModuleReference(moduleName=ericsson-enm-RcsHttpM, revision=5686-07-08, namespace=), ModuleReference(moduleName=ericsson-enm-RcsTimeM, revision=5758-04-25, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL3Router, revision=2431-11-02, namespace=), ModuleReference(moduleName=ericsson-enm-RsyncPtp, revision=8600-05-28, namespace=), ModuleReference(moduleName=ericsson-enm-R ... Line 1543: 2022-07-19 15:24:54.621 INFO [cps-application,ef4137071817ed67,ef4137071817ed67] 1 --- [ watchdog-th-5] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 109 ms for YangModelCmHandle is : YangModelCmHandle(id=7CCCA0A12CBA478FBC240A3E7F77D5B5, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:20:47.543+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,SubNetwork=NETSimW), YangModelCmHandle.Property(name=ossModelIdentity, value=21.Q1-R23A35), YangModelCmHandle.Property(name=nodeModelIdentity, value=21.Q1-R23A35), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=LTE40dg2ERBS00001)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-GNBDU, revision=2482-04-13, namespace=), ModuleReference(moduleName=ericsson-enm-ReqAntennaSystem, revision=6492-11-09, namespace=), ModuleReference(moduleName=ericsson-enm-Fgw, revision=8100-07-26, namespace=), ModuleReference(moduleName=ericsson-enm-RmeSectorEquipmentFunction, revision=2494-01-19, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL2EthernetPort, revision=6153-06-29, namespace=), ModuleReference(moduleName=ericsson-enm-RmeLicenseSupport, revision=6931-07-21, namespace=), ModuleReference(moduleName=ericsson-enm-GNBCUCP, revision=3091-07-24, namespace=), ModuleReference(moduleName=ericsson-enm-ResBatteryBackup, revision=9747-02-08, namespace=), ModuleReference(moduleName=ericsson-enm-ReqSupportUnit, revision=4126-03-09, namespace=), ModuleRe ... Line 2089: 2022-07-19 15:25:13.566 INFO [cps-application,ef4137071817ed67,ef4137071817ed67] 1 --- [ watchdog-th-5] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 6 ms for YangModelCmHandle is : YangModelCmHandle(id=2D12A3A6319C6E49FD7561A39F65301A, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:20:36.747+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=ossModelIdentity, value=5382-270-261), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,SubNetwork=NETSimW), YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=LTE98dg2ERBS00001), YangModelCmHandle.Property(name=nodeModelIdentity, value=5382-270-261)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-ReqAlarmPort, revision=5297-04-22, namespace=), ModuleReference(moduleName=ericsson-enm-RtnRoutesStaticRouteIPv6, revision=9658-06-27, namespace=), ModuleReference(moduleName=ericsson-enm-RtnIpsec, revision=2351-08-09, namespace=), ModuleReference(moduleName=ericsson-enm-ResBatteryBackup, revision=7324-08-14, namespace=), ModuleReference(moduleName=ericsson-enm-ReqTransceiver, revision=7705-05-22, namespace=), ModuleReference(moduleName=ericsson-enm-RcsPMEventM, revision=5680-03-10, namespace=), ModuleReference(moduleName=ericsson-enm-ReqExternalNode, revision=7324-08-14, namespace=), ModuleReference(moduleName=ericsson-enm-RtnIPv6ACLPolicy, revision=3731-01-03, namespace=), ModuleReference(moduleName=ericsson-enm-RtnPeerIpsecTunnel, revision=3733-02-12, namespace= ... Line 2550: 2022-07-19 15:25:28.354 INFO [cps-application,ef4137071817ed67,ef4137071817ed67] 1 --- [ watchdog-th-5] o.o.c.n.a.i.sync.ModuleSyncService : Time elapsed to getNewYangResourcesFromDmi is 5 ms for YangModelCmHandle is : YangModelCmHandle(id=7E27F1F511E9C1AB4913BC161862075B, dmiServiceName=, dmiDataServiceName=http://eric-eo-enm-adapter:80, compositeState=CompositeState(cmHandleState=ADVISED, lockReason=null, lastUpdateTime=2022-07-19T15:21:10.961+0000, dataSyncEnabled=null, dataStores=null), dmiModelServiceName=http://eric-oss-enm-model-adapter:8080, dmiProperties=[YangModelCmHandle.Property(name=neType, value=RadioNode), YangModelCmHandle.Property(name=targetNode, value=ManagedElement=RNC26MSRBS-V202), YangModelCmHandle.Property(name=ossModelIdentity, value=18.Q3-R49A16), YangModelCmHandle.Property(name=softwareSyncStatus, value=AS_IS), YangModelCmHandle.Property(name=subSystem, value=7), YangModelCmHandle.Property(name=nodeModelIdentity, value=18.Q3-R49A16), YangModelCmHandle.Property(name=targetDnPrefix, value=SubNetwork=Europe,SubNetwork=Ireland,SubNetwork=RNC26)], publicProperties=[YangModelCmHandle.Property(name=emsId, value=7)]) and IdentifiedNewModuleReferencesFromCmHandle : [ModuleReference(moduleName=ericsson-enm-Wrat, revision=4554-06-05, namespace=), ModuleReference(moduleName=ericsson-enm-ReqRiPort, revision=6550-10-12, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL3Router, revision=6406-03-22, namespace=), ModuleReference(moduleName=ericsson-enm-RtnSctp, revision=7182-05-16, namespace=), ModuleReference(moduleName=ericsson-enm-RsyncGnssInfo, revision=9738-09-21, namespace=), ModuleReference(moduleName=ericsson-enm-ReqTransceiver, revision=9732-09-12, namespace=), ModuleReference(moduleName=ericsson-enm-RcsCertM, revision=8104-10-14, namespace=), ModuleReference(moduleName=ericsson-enm-LratMce, revision=4025-06-15, namespace=), ModuleReference(moduleName=ericsson-enm-RtnL2VlanPort, revision=3207-12-28, namespace=), ModuleReference(moduleName=ericsson-enm-RtnLldp, ...References:

Jira Legacy

server	System Jira
columnIds	issuekey,summary,issuetype,created,updated,duedate,assignee,reporter,priority,status,resolution
columns	key,summary,type,created,updated,due,assignee,reporter,priority,status,resolution
serverId	4733707d-2057-3a0f-ae5e-4fd8aff50176
key	CPS-1126

Problem Statement

With previous versions we were able to register 10k cmhandles (in 4 threads) in 12 minutes.
With the current CPS master we sent the 10k cmHandles around 10 minutes to NCMP, so it is not faster than before. What I see is that NCMP starts getting modules in a background thread (seems to be one thread) and handling one cmhandle takes more seconds.
Currently in 12 minutes only 150 cmHandles got available with ready state in NCMP, because getting modules and changing the state is quite slow this way.

Expectation/ goal: cm-handle registration + module sync → 25 cm handles / sec (see CPS Interface Performance Requirements Overview)

Improvements Overview

Test Environment	Secs Taken for ModuleSyncWatchdog (Cm Handle moves ADVISED->READY)	Secs taken for Registration sub-process	Commit id	Parrealel Request to DMI	Main improvement	Comments
Ericsson Testing cluster (with Model adapter that is implementation of dmi-plugin) Total 1458 cm Handles	6,998 → 0.20/sec	2,278 → 0.64/sec	1410509e33142c0c79ff0e111c63abc47f5936d3 https://gerrit.onap.org/r/gitweb?p=cps.git;a=commit;h=1410509e33142c0c79ff0e111c63abc47f5936d3	N/A (1)	N/A	Baseline as per the bug
	600 → 2.43/sec	70 → 20.82/sec	c3596fe3a85381668598c75a1ffee4bf973a8518 https://gerrit.onap.org/r/c/cps/+/129829/5	N/A (1)	Created a dedicated threadpool for scheduler. - Tuned async threadpool of notification executor from setting RejectedExecutionHandler and application.yml. Note : Root cause : We have 3 watchdogs (2 @Scheduled into module sync and 1 into data sync) that was blocking each other as all @Scheduled methods share a single thread by default. )
	540 → 2.70 /sec	88(?!) → 16.57/sec	6e97bc6ee9f1cb2722aafc42325918e98da5cff2 https://gerrit.onap.org/r/c/cps/+/130058	N/A (1)	Mapped additional properties of YangModelCmHandle. @Async : scheduler are executing tasks asynchronously
	10,000 → 4.17 / sec 10K in 40 mins	N/A	0e7970a1ec12eac0f45fa016f98148da7a2266a8 https://gerrit.onap.org/r/c/cps/+/130946 (Master)	10	1. Introduced timeout for connect and reading for RestTemplate while connecting dmi-plugin. 2. Modified data structure of moduleSyncSemaphore to hold YangModelCmHandle referance (cm handle id) as key of map 3. Working of Modulewatchdog is modified with parallelism and broken into async tasks. 4. ModuleSyncSemaphoreMap is now populated with advised cm handles and processed by Modulewatchdog by batch size (Dynamic batch size at cm registration). 5. Introduled parallelism level for async tasks that are suppiled. 6. Includes cm handle registration preformance code change. 7. Performance Improvement: Postgres Pool Configuration 8. Performance Improvement: Async Notification Pool Configuration. 9. Performance Improvement: Save/update batch of CM-Handle States in one operation. 10. Performance Improvement: Updating (many) child datanodes/datanode tree into one SQL operation 11. Performance Improvement: Native query to more efficiently get all yangResourceIds. 12. Performance Improvement: Detaching fragment entities early. 13. Performance Improvement: Decouple Temporal DB Notification from main thread. Note : It includes bottleneck of in my recursive method (Joe K is working on it to improve. org.onap.cps.spi.impl.CpsDataPersistenceServiceImpl#toDataNode)
Local Development Machine with CSIT docker deployment (with dmi-plugin that is implemented by CPS team)	97+296 = 393 → 3.81 / sec	30 → 48.6 / sec	e367b520ac01432715b701af6e2bd75d4f81bccf https://gerrit.onap.org/r/c/cps/+/130148 (Latest)	5	Removed YangModelCmHandle object as key of map and stores only the reference that is cm handle id.	Note : It includes bottleneck of in recursive method (org.onap.cps.spi.impl.CpsDataPersistenceServiceImpl#toDataNode)Joe K is working on it to improve. 2. dmi-plugin is able to handle only 5-8 cm handle per seconds concurrently.
	125+378 = 503 → 2.98 / sec	33 → 45.45 / sec		10
	246 +356 = 602 → 2.49 / sec	31 → 48.39 / sec		30
Local Development Machine wit h dmi-plugin-perf-stub	10,000 → 4.76 / sec 10K in 35 mins	Not measured	0e7970a1ec12eac0f45fa016f98148da7a2266a8 https://gerrit.onap.org/r/c/cps/+/130946 (Master)	10	Using wiremock stub implemented by CPS team	100 requests of 100 cm handles each 2 sec between each requests

Test Configuration

Use Case

#	Configuration	Description
1	Number of CPS Instance	1
2	Total number of threads to send each batch (Register cm handle)	4
3	Batch size	100
4	To register 1458 cm handles	Used to send 15 batchs (100 cm handles in each batch)

CPS Parameters

#	Parameter	Value
1	timers: advised-modules-sync: sleep-time-ms:	30000
2	timers: locked-modules-sync: sleep-time-ms:	300000
3	timers: cm-handle-data-sync: sleep-time-ms:	30000
4	data-sync: cache: enabled:	false

Improvement Details

Performance matrix of improved methods that are called by ModuleSyncWatchdog or Cm handle registration API

Test Environment	Method	Sequential processing time (Task Parallelism Level = 1 )			Parallel processing time(Task Parallelism Level = 30)			Number of DB calls reduced by parallel / batch processing
Test Environment	Method	Best Case	Worst Case	Average	Best Case	Worst Case	Average	Number of DB calls reduced by parallel / batch processing
Local Development Machine with CSIT docker deployment (with dmi-plugin that is implemented by CPS team)	org.onap.cps.ncmp.api.impl.event.lcm.LcmEventsCmHandleStateHandlerImpl#registerNewCmHandle
	org.onap.cps.ncmp.api.inventory.InventoryPersistence#saveCmHandleStates
	org.onap.cps.spi.impl.CpsDataPersistenceServiceImpl#addChildDataNodes
	org.onap.cps.spi.impl.CpsDataPersistenceServiceImpl#replaceDataNodeTree
	org.onap.cps.spi.repository.FragmentRepositoryCpsPathQueryImpl#findByAnchorAndCpsPath
	org.onap.cps.spi.repository.SchemaSetYangResourceRepositoryImpl#insertSchemaSetIdYangResourceId
	org.onap.cps.spi.repository.YangResourceNativeRepository#getResourceIdsByModuleNameAndRevision

#	Operations	Average Time elapsed (in ~ ms)
1	To save cm handle state with id	Batch #.Iteration #	Time elapsed (in ~ ms)
		1.1	293
		1.2	84
		2.1	14
		2.2	8
		Average Time elapsed per cm handle (in ~ ms)	53
2	To synchronize, create schema set and anchor with id	Batch #.Iteration #	Time elapsed (in ~ ms)
		1.1	38393
		1.2	599
		2.1	237
		2.2	122
		Average Time elapsed per cm handle (in ~ ms)	0.483
3	Delete schema set If exists with id	Batch #.Iteration #	Time elapsed (in ~ ms)
		1.1	17
		1.2	2
		2.1	2
		2.2	2
		Average Time elapsed per cm handle (in ~ ms)	11.5
4	Get cm handle state with id	Batch #.Iteration #	Time elapsed (in ~ ms)
		1.1	83
		1.2	7
		2.1	10
		2.2	12
		Average Time elapsed per cm handle (in ~ ms)	56
5	To get yang models	Batch #	Batch Size	Time elapsed (in ~ ms)	Time elapsed per cm handle (in ~ ms)
		1	601	63107	105.00
		2	857	37337	43.56
		Average Time elapsed per iteration (in ~ ms)			74.28
6	To shuffle cm handles	Batch #	Batch Size	Time elapsed (in ~ ms)
		1	601	0
		2	857	0
		Average Time elapsed per iteration (in ~ ms)			0
7	Get / fetch cm handles by state ADVISED	Batch #	Batch Size	Time elapsed (in ~ ms)	Time elapsed per cm handle (in ~ ms)
		1	601	19404	32.28
		2	857	3485	4.06
		Average Time elapsed per iteration (in ~ ms)			18.17

Versions Compared

Old Version 4

New Version Current

Key

Overview :

Problem Statement

Improvements Overview

Test Configuration

Improvement Details