Performance of "sfpowerkit:source:profile:reconcile -s" have dropped in ~25 times between versions 4.0.3 and 4.2.5*

[busybox0]

Performance of command "sfdx sfpowerkit:source:profile:reconcile -s" have dropped in ~25 times since version 4.0.3

Here and below I'm refering to version with included fix for https://github.com/Accenture/sfpowerkit/issues/662 that is on top of 4.2.5

version 4.0.3 - swallows and returns profile with initial 25k lines in 1.630s

$ time sfdx sfpowerkit:source:profile:reconcile -n Admin -s
-------------------------------------------------------------------------------------------
sfpowerkit  -- The DX@Scale Developer Toolkit -Version:4.0.3 -Release:January 22
-------------------------------------------------------------------------------------------
INFO [2022-04-26 09:54:07.078 +0000] (sfpowerkit): Reconciling profile /home/ubuntu/xxx/force-app/main/default/profiles/Admin.profile-meta.xml
State    Full Name  Type     Path
───────  ─────────  ───────  ──────────────────────────────────────────────────────
Cleaned  Admin      Profile  force-app/main/default/profiles/Admin.profile-meta.xml

real    0m1.630s
user    0m1.988s
sys     0m0.214s

Current version with the same initial 25k lines profile (even after ~/sfpowerkit/sfpowerkit-cache.db it created, so it's 2nd launch on the same initial material) is 41.564s:

root@1ac67c0b14c4:/build # time sfdx sfpowerkit:source:profile:reconcile -n Admin -s
-------------------------------------------------------------------------------------------
sfpowerkit  -- The DX@Scale Developer Toolkit - Version:4.2.5 - Release:April 22
-------------------------------------------------------------------------------------------
Profiles Found in Project Directory 1
Initiated Profile reconcile thread :1  with a chunk of 1 profiles
Profiles queued in thread :1 :
[{"path":"force-app/main/default/profiles/Admin.profile-meta.xml","name":"Admin"}]
Reconciled Profile force-app/main/default/profiles/Admin.profile-meta.xml
State    Full Name  Type     Path
───────  ─────────  ───────  ──────────────────────────────────────────────────────
Cleaned  Admin      Profile  force-app/main/default/profiles/Admin.profile-meta.xml

real    0m41.564s
user    0m10.769s
sys     0m3.400s

If we let it take all 60 profiles the project has (omitting -n option, just time sfdx sfpowerkit:source:profile:reconcile -s then 4.0.3 is

real    0m12.420s
user    0m15.199s
sys     0m0.970s

while 4.2.5 (with included https://github.com/Accenture/sfpowerkit/issues/662 ) is

real    4m44.058s
user    1m32.449s
sys     0m24.740s

which is giving a ratio around 23 - the latest version 23 times slower than 4.0.3.

• OS: Ubuntu Linux in WSL2
• sfdx-cli/7.146.1 linux-x64 node-v16.14.2

[Caitlyn-Mills]

Thanks for reporting the issue @busybox0 we will look into it.

[Caitlyn-Mills]

@busybox0 can you check 4.2.7 and see if you are still having the same performance drop?

[busybox0]

@Caitlyn-Mills @azlam-abdulsalam It's 4.2.8 and still one profile reconcile takes minutes. Seems there is performance increase if many profiles are being reconciled, i.e. time increase is not in linear dependency with amount of profiles. Will provide accurate stats soon.

[loktevich]

@Caitlyn-Mills @azlam-abdulsalam Here are our stats when reconciling 1 profile (30k lines before reconciling)

$ time sfdx sfpowerkit:source:profile:reconcile -f profiles -n Admin -s
-------------------------------------------------------------------------------------------
sfpowerkit  -- The DX@Scale Developer Toolkit - Version:4.2.8 - Release:May 22
-------------------------------------------------------------------------------------------
Profiles Found in Project Directory 1
Initiated Profile reconcile thread :1  with a chunk of 1 profiles
Profiles queued in thread :1 :
[{"path":"profiles\\Admin.profile-meta.xml","name":"Admin"}]
Reconciled Profile profiles\Admin.profile-meta.xml
State    Full Name  Type     Path
───────  ─────────  ───────  ───────────────────────────────
Cleaned  Admin      Profile  profiles\Admin.profile-meta.xml

real    3m23.177s
user    0m0.400s
sys     0m0.153s

and these for 25 profiles (each 27-30k lines)

$ time sfdx sfpowerkit:source:profile:reconcile -f profiles -s
-------------------------------------------------------------------------------------------
sfpowerkit  -- The DX@Scale Developer Toolkit - Version:4.2.8 - Release:May 22             
-------------------------------------------------------------------------------------------
Profiles Found in Project Directory 25
Initiated Profile reconcile thread :1  with a chunk of 1 profiles
Profiles queued in thread :1 :
[{"path":"profiles\\Admin.profile-meta.xml","name":"Admin"}]
Reconciled Profile profiles\Admin.profile-meta.xml
Initiated Profile reconcile thread :1  with a chunk of 10 profiles
Profiles queued in thread :1 :
[{"path":"profiles\\Certification Request Profile.profile-meta.xml","name":"Certification Request Profile"},{"path":"profiles\\Chatter Free User.profile-meta.xml","name":"Chatter Free User"},{"path":"profiles\\CT_Basic User.profile-
meta.xml","name":"CT_Basic User"},{"path":"profiles\\CT_Contractor.profile-meta.xml","name":"CT_Contractor"},{"path":"profiles\\CT_Delivery Head.profile-meta.xml","name":"CT_Delivery Head"},{"path":"profiles\\CT_Department Manager.p
rofile-meta.xml","name":"CT_Department Manager"},{"path":"profiles\\CT_HR Manager.profile-meta.xml","name":"CT_HR Manager"},{"path":"profiles\\CT_LnD.profile-meta.xml","name":"CT_LnD"},{"path":"profiles\\CT_Presale manager.profile-m
eta.xml","name":"CT_Presale manager"},{"path":"profiles\\CT_Presale MSI manager.profile-meta.xml","name":"CT_Presale MSI manager"}]
Initiated Profile reconcile thread :2  with a chunk of 10 profiles
Profiles queued in thread :2 :
[{"path":"profiles\\CT_Project Manager.profile-meta.xml","name":"CT_Project Manager"},{"path":"profiles\\CT_Recruiter.profile-meta.xml","name":"CT_Recruiter"},{"path":"profiles\\CT_Resource Manager.profile-meta.xml","name":"CT_Resou
rce Manager"},{"path":"profiles\\CT_Restricted SysAdmin.profile-meta.xml","name":"CT_Restricted SysAdmin"},{"path":"profiles\\CT_Restricted_POW_Admin.profile-meta.xml","name":"CT_Restricted_POW_Admin"},{"path":"profiles\\CT_Sales Ma
nager.profile-meta.xml","name":"CT_Sales Manager"},{"path":"profiles\\CT_Salesforce_Standard.profile-meta.xml","name":"CT_Salesforce_Standard"},{"path":"profiles\\CT_ScratchOrgUser.profile-meta.xml","name":"CT_ScratchOrgUser"},{"pat
h":"profiles\\CT_Standart User.profile-meta.xml","name":"CT_Standart User"},{"path":"profiles\\CT_Travel Manager.profile-meta.xml","name":"CT_Travel Manager"}]
Initiated Profile reconcile thread :3  with a chunk of 4 profiles
Profiles queued in thread :3 :
[{"path":"profiles\\Employee Portal Profile.profile-meta.xml","name":"Employee Portal Profile"},{"path":"profiles\\Hubspot Integration.profile-meta.xml","name":"Hubspot Integration"},{"path":"profiles\\Marketo Sync.profile-meta.xml"
,"name":"Marketo Sync"},{"path":"profiles\\Sys Admin POW.profile-meta.xml","name":"Sys Admin POW"}]
Reconciled Profile profiles\Employee Portal Profile.profile-meta.xml
Reconciled Profile profiles\Hubspot Integration.profile-meta.xml
Reconciled Profile profiles\Marketo Sync.profile-meta.xml
Reconciled Profile profiles\Sys Admin POW.profile-meta.xml
Reconciled Profile profiles\CT_Project Manager.profile-meta.xml
Reconciled Profile profiles\CT_Recruiter.profile-meta.xml
Reconciled Profile profiles\CT_Resource Manager.profile-meta.xml
Reconciled Profile profiles\CT_Restricted SysAdmin.profile-meta.xml
Reconciled Profile profiles\CT_Restricted_POW_Admin.profile-meta.xml
Reconciled Profile profiles\CT_Sales Manager.profile-meta.xml
Reconciled Profile profiles\CT_Salesforce_Standard.profile-meta.xml
Reconciled Profile profiles\CT_ScratchOrgUser.profile-meta.xml
Reconciled Profile profiles\CT_Standart User.profile-meta.xml
Reconciled Profile profiles\CT_Travel Manager.profile-meta.xml
Reconciled Profile profiles\Certification Request Profile.profile-meta.xml
Reconciled Profile profiles\Chatter Free User.profile-meta.xml
Reconciled Profile profiles\CT_Basic User.profile-meta.xml
Reconciled Profile profiles\CT_Contractor.profile-meta.xml
Reconciled Profile profiles\CT_Delivery Head.profile-meta.xml
Reconciled Profile profiles\CT_Department Manager.profile-meta.xml
Reconciled Profile profiles\CT_HR Manager.profile-meta.xml
Reconciled Profile profiles\CT_LnD.profile-meta.xml
Reconciled Profile profiles\CT_Presale manager.profile-meta.xml
Reconciled Profile profiles\CT_Presale MSI manager.profile-meta.xml
State    Full Name                      Type     Path
───────  ─────────────────────────────  ───────  ───────────────────────────────────────────────────────
Cleaned  Admin                          Profile  profiles\Admin.profile-meta.xml
Cleaned  Employee Portal Profile        Profile  profiles\Employee Portal Profile.profile-meta.xml
Cleaned  Hubspot Integration            Profile  profiles\Hubspot Integration.profile-meta.xml
Cleaned  Marketo Sync                   Profile  profiles\Marketo Sync.profile-meta.xml
Cleaned  Sys Admin POW                  Profile  profiles\Sys Admin POW.profile-meta.xml
Cleaned  CT_Project Manager             Profile  profiles\CT_Project Manager.profile-meta.xml
Cleaned  CT_Recruiter                   Profile  profiles\CT_Recruiter.profile-meta.xml
Cleaned  CT_Resource Manager            Profile  profiles\CT_Resource Manager.profile-meta.xml
Cleaned  CT_Restricted SysAdmin         Profile  profiles\CT_Restricted SysAdmin.profile-meta.xml
Cleaned  CT_Restricted_POW_Admin        Profile  profiles\CT_Restricted_POW_Admin.profile-meta.xml
Cleaned  CT_Sales Manager               Profile  profiles\CT_Sales Manager.profile-meta.xml
Cleaned  CT_Salesforce_Standard         Profile  profiles\CT_Salesforce_Standard.profile-meta.xml
Cleaned  CT_ScratchOrgUser              Profile  profiles\CT_ScratchOrgUser.profile-meta.xml
Cleaned  CT_Standart User               Profile  profiles\CT_Standart User.profile-meta.xml
Cleaned  CT_Travel Manager              Profile  profiles\CT_Travel Manager.profile-meta.xml
Cleaned  Certification Request Profile  Profile  profiles\Certification Request Profile.profile-meta.xml
Cleaned  Chatter Free User              Profile  profiles\Chatter Free User.profile-meta.xml
Cleaned  CT_Basic User                  Profile  profiles\CT_Basic User.profile-meta.xml
Cleaned  CT_Contractor                  Profile  profiles\CT_Contractor.profile-meta.xml
Cleaned  CT_Delivery Head               Profile  profiles\CT_Delivery Head.profile-meta.xml
Cleaned  CT_Department Manager          Profile  profiles\CT_Department Manager.profile-meta.xml
Cleaned  CT_HR Manager                  Profile  profiles\CT_HR Manager.profile-meta.xml
Cleaned  CT_LnD                         Profile  profiles\CT_LnD.profile-meta.xml
Cleaned  CT_Presale manager             Profile  profiles\CT_Presale manager.profile-meta.xml
Cleaned  CT_Presale MSI manager         Profile  profiles\CT_Presale MSI manager.profile-meta.xml

real    13m16.088s
user    0m0.275s
sys     0m0.076s

Also it was noticed that firstly initiated reconcile thread contains a chunk with 1 profile. And every time the next initiated thread has the same number 1, but contains a chunk with 10 profiles. Each run we get close results. And it seems that each reconcile thread is lasting for approximately 3.25 minutes that is very close to the time of reconciling just one profile.

• OS: Microsoft Windows [Version 10.0.19044.1766]
• sfdx-cli/7.151.1 win32-x64 node-v14.18.2