Slow performance of AdvancedPermissionChecker#getUserBag() when a user is a member of several groups

• Type: Bug
• Status: Closed
• Resolution: Fixed
• Affects Version/s: 6.1.20 EE GA2, 7.0.0 M3
• Fix Version/s: 6.1.X EE, 6.2.4 CE GA5, 6.2.X EE, 7.0.0 M1
• Component/s: Core Infrastructure, Core Infrastructure > Permissions, Performance, Security Vulnerability
• Labels:
  • 6.1_release_notes
  • QA-KC
  • QA-TP
  • ee-ts
  • liferay-fixpack-portal-44-6130
  • liferay-fixpack-portal-50-6210
  • performance
• Branch Version/s:
  6.2.x, 6.1.x
• Backported to Branch:
  Committed
• Story Points: 28
• Fix Priority: 4
• Git Pull Request: https://github.com/brianchandotcom/liferay-portal/pull/16948

Steps to reproduce

1) Deploy DataManipulator from my branch: https://github.com/laszlocsontos/DataManipulator/tree/LPS-44236
2) Log in with [email protected]
3) Underneth Control Panel / Apps choose Data Manipulator (Custom)
4) From Entry Types choose LPS-44236
5) Click Save

6) Wait for the process to be finished.

a) Click on Data Manipulator (Custom) to see the number of entries generated so far.
b) Notice the following messages in the log, you'll need the test user's email address and the company ID in further steps

07:47:25,079 ERROR [Thread-36][DataManipulatorRunner:42] Thread-36 start add entries at 1392277645079.
07:47:25,682 ERROR [Thread-36][CustomVocabularyHandler:68] *** Created user: [email protected] / password: test
07:47:25,682 ERROR [Thread-36][CustomVocabularyHandler:72] *** Company ID: 10156
07:48:06,796 ERROR [Thread-36][DataManipulatorRunner:58] Thread-36 finish add entries at 1392277686796.
07:48:06,796 ERROR [Thread-36][DataManipulatorRunner:62] The whole process takes 41717ms.

7) Underneath Control Panel / Configuration / Server Admin / Log Levels increase the log level of com.liferay.portal.security.permission.AdvancedPermissionChecker to DEBUG.

8) Log in with [email protected]
9) Navigate to the following URL (replace the hostname / port according to your config if needed)

http://localhost:8080/api/jsonws?signature=%2Fassetvocabulary%2Fget-company-vocabularies-1-companyId

10) Enter the company ID you noted earlier and click Invoke ~
11) In the logs you can see that each call to AdvancedPermissionChecker takes ~370ms, which means that for getting the 1000 entries you generated before will take ~6mins.

07:53:27,769 DEBUG [http-bio-9080-exec-2][AdvancedPermissionChecker:1339] Checking user permission block 1 for 11408 com.liferay.portlet.asset.model.AssetVocabulary 11412 VIEW takes 369 ms
07:53:27,770 DEBUG [http-bio-9080-exec-2][AdvancedPermissionChecker:1339] Checking user permission block 3 for 11408 com.liferay.portlet.asset.model.AssetVocabulary 11412 VIEW takes 370 ms
07:53:27,770 DEBUG [http-bio-9080-exec-2][AdvancedPermissionChecker:1339] Checking user permission block 4 for 11408 com.liferay.portlet.asset.model.AssetVocabulary 11412 VIEW takes 370 ms
07:53:27,771 DEBUG [http-bio-9080-exec-2][AdvancedPermissionChecker:589] Checking permission for 11408 com.liferay.portlet.asset.model.AssetVocabulary 11412 VIEW takes 372 ms