Identity Manager takes long to start - troubleshooting

book

Article ID: 192413

calendar_today

Updated On:

Products

CA Identity Manager CA Identity Suite

Issue/Introduction

During Identity Manager startup, there is a long delay between steps 4 and 5. Depending on the size of the environment (number of screens / tasks / tabs etc) - this could take quite a while

Environment

Identity Manager 14.x

Resolution

In order to troubleshoot where time is spent, we need to configure enhanced logging to be in place during startup. This can be done by adjusting the relevant categories in the file "log4j_<ApplicationServer.properties>" located in the deployed IM .ear location, for example E:\wildfly-8.2.1.Final\standalone\deployments\iam_im.ear\config\com\netegrity\config\log4j_jboss.properties and set

log4j.category.ims.jdbc=DEBUG

This will remain in place for each subsequent restart, till changed.

With the above settings in place, should be waiting for startup process to complete, then search for the following entries (in separate searches):

- Obj type:
- Finished loading cache for

Search results should look similar to

2020-06-07 07:06:43,748 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM MOBJ DEF, cache obj count: 8
2020-06-07 07:06:43,826 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM DIRECTORY, cache obj count: 3
2020-06-07 07:06:44,858 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: SMS CONFIGURATION, cache obj count: 0
2020-06-07 07:06:48,420 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM MOBJ ATTR DEF, cache obj count: 297
2020-06-07 07:06:49,030 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM CERTIFICATION POLICY, cache obj count: 0
2020-06-07 07:06:49,264 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM VALIDATION RULE, cache obj count: 17
2020-06-07 07:06:49,373 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM VALIDATION SET, cache obj count: 17
2020-06-07 07:06:49,405 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM DIR CONNECTION, cache obj count: 3
2020-06-07 07:06:49,546 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: CA SERVICE CONNECTION, cache obj count: 0
2020-06-07 07:06:49,764 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: USECASE, cache obj count: 0
2020-06-07 07:06:49,920 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: WORKFLOW TEMPLATE, cache obj count: 0
2020-06-07 07:06:50,030 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM WEBSERVICE CONFIG, cache obj count: 0
2020-06-07 07:06:50,046 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM WEBSERVICE CUSTOM, cache obj count: 0
2020-06-07 07:06:50,062 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM WS TRUST CONFIG, cache obj count: 0
2020-06-07 07:06:50,280 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: PX WHEN, cache obj count: 25
2020-06-07 07:06:50,514 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: PX POLICY, cache obj count: 23
2020-06-07 07:06:50,546 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM APPROVAL POLICY, cache obj count: 2
2020-06-07 07:06:50,592 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM IDENTITY POLICY, cache obj count: 1
2020-06-07 07:06:50,639 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM IDENTITY POLICY SET, cache obj count: 1
2020-06-07 07:06:51,326 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM MEMBER POLICY, cache obj count: 100
2020-06-07 07:06:51,436 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM ADMIN POLICY, cache obj count: 88
2020-06-07 07:06:51,670 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM OWNER POLICY, cache obj count: 107
2020-06-07 07:06:51,796 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM TASK HANDLER, cache obj count: 30
2020-06-07 07:06:54,545 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM TASK, cache obj count: 605
2020-06-07 07:07:01,921 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM ROLE, cache obj count: 103
2020-06-07 07:07:42,514 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM SCREEN, cache obj count: 560
2020-06-07 07:07:50,436 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM TAB, cache obj count: 1237
2020-06-07 07:07:50,467 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM TAB DEFINITION, cache obj count: 2
2020-06-07 07:07:50,498 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM SCREEN DEFINITION, cache obj count: 2
2020-06-07 07:07:50,530 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: TASK RESUBMISSION POLICY, cache obj count: 1
2020-06-07 07:07:50,608 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Obj type: IM ENVIRONMENT JDBC, cache obj count: 2

and the time each object time took (in milliseconds)

2020-06-07 07:06:43,748 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM MOBJ DEF; Time taken: 140
2020-06-07 07:06:43,826 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM DIRECTORY; Time taken: 343
2020-06-07 07:06:44,858 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for SMS CONFIGURATION; Time taken: 15
2020-06-07 07:06:48,420 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM MOBJ ATTR DEF; Time taken: 3297
2020-06-07 07:06:49,030 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM CERTIFICATION POLICY; Time taken: 0
2020-06-07 07:06:49,264 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM VALIDATION RULE; Time taken: 0
2020-06-07 07:06:49,373 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM VALIDATION SET; Time taken: 78
2020-06-07 07:06:49,405 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM DIR CONNECTION; Time taken: 16
2020-06-07 07:06:49,546 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for CA SERVICE CONNECTION; Time taken: 16
2020-06-07 07:06:49,764 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for USECASE; Time taken: 0
2020-06-07 07:06:49,920 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for WORKFLOW TEMPLATE; Time taken: 16
2020-06-07 07:06:50,030 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM WEBSERVICE CONFIG; Time taken: 0
2020-06-07 07:06:50,046 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM WEBSERVICE CUSTOM; Time taken: 0
2020-06-07 07:06:50,062 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM WS TRUST CONFIG; Time taken: 0
2020-06-07 07:06:50,280 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for PX WHEN; Time taken: 626
2020-06-07 07:06:50,514 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for PX POLICY; Time taken: 937
2020-06-07 07:06:50,546 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM APPROVAL POLICY; Time taken: 1344
2020-06-07 07:06:50,608 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM IDENTITY POLICY; Time taken: 1437
2020-06-07 07:06:50,639 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM IDENTITY POLICY SET; Time taken: 1531
2020-06-07 07:06:51,326 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM MEMBER POLICY; Time taken: 2280
2020-06-07 07:06:51,436 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM ADMIN POLICY; Time taken: 2468
2020-06-07 07:06:51,670 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM OWNER POLICY; Time taken: 2812
2020-06-07 07:06:51,811 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM TASK HANDLER; Time taken: 3031
2020-06-07 07:06:54,545 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM TASK; Time taken: 5812
2020-06-07 07:07:01,921 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM ROLE; Time taken: 13267
2020-06-07 07:07:42,514 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM SCREEN; Time taken: 54078
2020-06-07 07:07:50,436 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM TAB; Time taken: 65422
2020-06-07 07:07:50,467 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM TAB DEFINITION; Time taken: 65500
2020-06-07 07:07:50,498 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM SCREEN DEFINITION; Time taken: 65624
2020-06-07 07:07:50,530 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for TASK RESUBMISSION POLICY; Time taken: 66625
2020-06-07 07:07:50,608 DEBUG [ims.jdbc.JDBCManagedObjectProvider] (MSC service thread 1-2) Finished loading cache for IM ENVIRONMENT JDBC; Time taken: 68063

When certain object load time takes long, we need to look into possible index settings we can apply, to speed up the process

Additional Information

For adding indexes to the screen tables (where time is usually spent), please follow

https://knowledge.broadcom.com/external/article?articleId=28852