Performance Tuning for Content Manager

Chapter 12. Troubleshooting performance problems 357

ICMPLSMM ICMLISTMIMETYPE 00259 05/30 18:39:07.906 GMT ; ... JOHN 4 msec

ICMPLSGA ICMGETATTRTYPE 00412 05/30 18:39:07.926 GMT ; ... JOHN 3 msec

ICMPLSGT ICMGETITEMTYPE 00919 05/30 18:39:08.056 GMT ; ... JOHN 98 msec

ICMPLSLX ICMLISTXDOOBJECT 00335 05/30 18:39:08.066 GMT ; ... JOHN 3 msec

ICMPLSGA ICMGETATTRTYPE 00412 05/30 18:39:08.076 GMT ; ... JOHN 2 msec

ICMPLSLK ICMLISTNLSKEYWRD 00860 05/30 18:39:08.236 GMT ; ... JOHN 1 msec

12.3.2 DB2 UDB connection

In the logon process, the client needs to connect to the Library Server database

successfully and then calls the stored procedures. If the database connection is

very slow, the whole logon process will be very slow as well.

For example, in one scenario, some user IDs logged on to the system very slowly

(around 1-5 minutes), while others were as usual. We set the trace level to 15 and

examined the ICMSERVER.LOG file, which included the data when a “good” ID

and a “bad” ID logged on to the system. A good ID means that this ID has no

logon performance issues, and a bad ID has a logon performance issue. For this

scenario, TB774 was the good ID and T4834 was the bad ID.

Example 12-6 shows the extracted information from the ICMSERVER.LOG file.

Example 12-6 ICMSERVER.log with both good ID and bad ID log on to the system

ICMPLSLG ICMLOGON 00525 02/22 17:00:08.717

?22170008716468 Input

UserID <TB774>

DB2UserID <TB774>

......

ICMPLSLG ICMLOGON 00525 02/22 17:04:18.158

?22170418157471 Input

UserID <T4834>

DB2UserID <ICMCONCT>

Because user TB774 connected to Library Server database (DB2UserID

<TB774> in the log file), we assumed that user TB774 is an operating system

user ID. User T4834 used ICMCONCT to connect to the Library Server database

(DB2UserID <ICMCONCT> in the log file), so we assumed that user T4834 is a

Content Manager internal user ID or an LDAP user ID.

With further examination in this case, we found the following information:

 Users who had no performance issues were the ones using the operating

system user IDs, such as TB774.

 Those operating system user IDs have the database connection privilege.

358 Performance Tuning for Content Manager

 The operating system IDs connected to the Library Server database using

their own user IDs instead of ICMCONCT.

 Users who had performance issues were Content Manager internal user IDs.

Then, we calculated the total time the stored procedures used for logon process

on user ID TB774 and T4834. We found that TB774 spent more time on stored

procedures execution than T4834. That is, the bad one finished the stored

procedure calls more quickly than the good one.

For the good one (the operating system user ID), we extracted the information

from the ICMSERVER.LOG file as shown in Example 12-7.

Example 12-7 ICMSERVER.LOG with good user ID

ICMPLSLG ICMLOGON 01393 02/22 17:00:08.726 ?22170008716468 10 msec

ICMPLSLS ICMLISTCNTRLPARM 00271 02/22 17:00:09.126 ?22170008716468 2 msec

ICMPLSLK ICMLISTNLSKEYWRD 00499 02/22 17:00:09.250 ?22170008716468 1 msec

ICMPLSLP ICMLISTPRIVILEGE 00374 02/22 17:00:09.552 ?22170008716468 3 msec

ICMPLSGA ICMGETATTRTYPE 00286 02/22 17:00:09.798 ?22170008716468 3 msec

ICMPLSGT ICMGETITEMTYPE 00588 02/22 17:00:10.140 ?22170008716468 83 msec

ICMPLSLX ICMLISTXDOOBJECT 00226 02/22 17:00:10.404 ?22170008716468 1 msec

ICMPLSGA ICMGETATTRTYPE 00286 02/22 17:00:10.719 ?22170008716468 1 msec

ICMPLSCL ICMLISTCOLL 00486 02/22 17:00:11.860 ?22170008716468 2 msec

ICMPLSLK ICMLISTNLSKEYWRD 00499 02/22 17:00:12.013 ?22170008716468 1 msec

ICMPLSQU ICMSEARCH 00228 02/22 17:00:12.261 ?22170008716468 16 msec

ICMPLSCL ICMLISTCOLL 00486 02/22 17:00:12.489 ?22170008716468 2 msec

ICMPLSLK ICMLISTNLSKEYWRD 00499 02/22 17:00:12.652 ?22170008716468 2 msec

ICMPLSLK ICMLISTNLSKEYWRD 00499 02/22 17:00:12.899 ?22170008716468 1 msec

ICMPLSLC ICMLISTCOMPILEDACL 00337 02/22 17:00:13.160 ?22170008716468 27 msec

ICMPLSMM ICMLISTMIMETYPE 00181 02/22 17:00:13.439 ?22170008716468 2 msec

ICMPLSQU ICMSEARCH 00228 02/22 17:00:13.697 ?22170008716468 13 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:00:13.800 ?22170008716468 17 msec

ICMPLSQU ICMSEARCH 00228 02/22 17:00:15.512 ?22170008716468 10 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:00:15.610 ?22170008716468 14 msec

ICMPLSQU ICMSEARCH 00228 02/22 17:00:16.445 ?22170008716468 11 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:00:16.674 ?22170008716468 25 msec

ICMPLSQU ICMSEARCH 00228 02/22 17:00:32.175 ?22170008716468 5259 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:00:33.797 ?22170008716468 60 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:00:36.913 ?22170008716468 231 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:00:39.065 ?22170008716468 52 msec

ICMPLSCO ICMCHECKOUTITEM 00407 02/22 17:01:23.414 ?22170008716468 41 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:01:23.615 ?22170008716468 30 msec

ICMPLSGD ICMGETDOCTOC 00598 02/22 17:01:23.862 ?22170008716468 8 msec

ICMPLSGI ICMGETITEM 03832 02/22 17:01:24.068 ?22170008716468 22 msec

ICMPLSLM ICMLISTRESOURCEMGR 00788 02/22 17:01:24.169 ?22170008716468 13 msec

ICMPLSCI ICMCHECKINITEM 00387 02/22 17:03:30.651 ?22170008716468 22 msec

ICMPLSLF ICMLOGOFF 00176 02/22 17:03:34.061 ?22170008716468 1 msec