Identity Manager takes a long time to start - delay between steps 4 and 5
search cancel

Identity Manager takes a long time to start - delay between steps 4 and 5

book

Article ID: 192413

calendar_today

Updated On:

Products

CA Identity Manager CA Identity Suite

Issue/Introduction

During Identity Manager startup, there is a can be a long delay between steps 4 and 5 depending on the size of the environment (number of screens / tasks / tabs etc) 

Can the startup performance be improved?

Environment

Identity Manager 14.x

Resolution

Identity Manager startup has to query and do an initial load and verification of all defined Rolls and Tasks, which in larger environments can take a significant amount of time.    Working with your DBA to add indexes can improve the overall startup performance. 

 

EXAMPLE;

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 <wildfly_home>\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.


Alternatively, configure ims.jdbc=DEBUG logging in the logging_v2.jsp as described in the Documentation Setup Log4j2 Log Levels Using the Logging Admin Tool this configuration reverts on restart of the application server. 

 

 

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

- Obj type:

- Finished loading cache


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, work with your DBA to review and add indexes to speed up the process.

For example from the above log results, the following SQL on the object store database should decrease Identity Manager startup time during step 4 and 5.


-- Adding indices for Objectstore tables IM_SCREEN_LD & IM_SCREEN_FIELD_LD
create index [idx_IM_SCREEN_LD] on [dbo].[IM_SCREEN_LD] ([REF_ID])
GO
create index [idx_IM_SCREEN_FIELD_LD] on [dbo].[IM_SCREEN_FIELD_LD]
([REF_ID])
GO

 

 

Please work with the DBA, they should have tools to help analyze database performance and can make additional environmental specific indexing recommendations. 

 

NOTE:  Before any changes are made to a Production database, please ensure a backup exists in place.

Powered by Wolken Software