|
Problem IT19945
|
Status: Closed |
HIGH NUMBER OF CATCACHE LOCKS IMPACTING PERFORMANCE OF QUERIES
|
| product: |
DB2 FOR LUW / DB2FORLUW / A10 - DB2 |
| Problem description: |
in some cases when a user has many roles/groups associated with
it and one of the role entries is evicted from the catalog cache
either due to the catalog cache space or revoke privilege
executed against a user/role, the transactions may go into a
loop while holding catcache locks trying to load the evicted
entries however exiting without loading since they have found
another entry with execute privilege.
This can cause slowdowns on the running transactions by this
user when the transactions accessing the same number of entries
in catalog cache are high.
in db2pd -wlocks output collected at the time of the issue, the
following locks are observed:
Database Partition 0 -- Database sample -- Active -- Up 14 days
11:10:13 -- Date 2017-03-26-15.19.04.604923
Locks being waited on :
AppHandl [nod-index] TranHdl Lockname Type
Mode Conv Sts CoorEDU AppName AuthID AppID
46484 [000-46484] 198 000C000007000027041B8C0043
CatCache ..X G 271486 db2jcc_a DB2INST1
169.83.182.180.57417.170326191124
46014 [000-46014] 4231 000C000007000027041B8C0043
CatCache ..X W 259947 db2jcc_a DB2INST1
169.83.182.192.38660.170326191102
47612 [000-47612] 166 000C000007000027041B8C0043
CatCache ..X W 340455 db2jcc_a DB2INST1
169.83.182.192.40956.170326191344
46011 [000-46011] 696 000C000007000027041B8C0043
CatCache ..X W 296603 db2jcc_a DB2INST1
169.83.182.180.57855.170326191152
46826 [000-46826] 801 000C000007000027041B8C0043
CatCache ..X W 204850 db2jcc_a DB2INST1
169.83.182.192.37128.170326190957
45583 [000-45583] 1845 000C000007000027041B8C0043
CatCache ..X W 81454 db2jcc_a DB2INST1
169.83.182.198.37344.170326190530
56652 [000-56652] 2641 000C000007000027041B8C0043
CatCache ..X W 365080 db2jcc_a DB2INST1
169.83.182.178.39586.170326191420
50418 [000-50418] 2863 000C000007000027041B8C0043
CatCache ..X W 171760 db2jcc_a DB2INST1
169.83.182.183.56918.170326190210
50187 [000-50187] 112 000C000007000027041B8C0043
CatCache ..X W 286552 db2jcc_a DB2INST1
169.83.182.197.45120.170326190245
45978 [000-45978] 1923 000C000007000027041B8C0043
CatCache ..X W 222794 db2jcc_a DB2INST1
169.83.182.180.55558.170326191017
47193 [000-47193] 595 000C000007000027041B8C0043
CatCache ..X W 41653 db2jcc_a DB2INST1
169.83.182.197.45147.170326190328
53990 [000-53990] 4692 000C000007000027041B8C0043
CatCache ..X W 113516 db2jcc_a DB2INST1
169.83.182.194.56379.170326190633
47135 [000-47135] 1566 000C000007000027041B8C0043
CatCache ..X W 254559 db2jcc_a DB2INST1
169.83.182.180.46994.170326185546
49991 [000-49991] 740 000C000007000027041B8C0043
CatCache ..X W 87615 db2jcc_a DB2INST1
169.83.182.184.64110.170326190546
43645 [000-43645] 2451 000C000007000027041B8C0043
CatCache ..X W 184845 db2jcc_a DB2INST1
169.83.182.184.44246.170326185304
49905 [000-49905] 399 000C000007000027041B8C0043
CatCache ..X W 264308 db2jcc_a DB2INST1
169.83.182.178.64591.170326191108
45345 [000-45345] 2657 000C000007000027041B8C0043
CatCache ..X W 314641 db2jcc_a DB2INST1
169.83.182.188.43949.170326185530
>> skipping
The stack dump of the agents involved in catcache lock may look
like this:
0x0900000000118F98 thread_wait + 0x98
0x09000000158C7D64 sqloWaitEDUWaitPost + 0x1D0
0x09000000158C80BC
IntrptWaitLock__18@87@96040@sqeAgentFP16SQLO_EDUWAITPOSTiPUiT2 +
0x54
0x090000001595AAC0
sqlplnfd__FP9sqeBsuEduP14SQLP_LOCK_INFOP8SQLP_LCBP9SQLP_LHSHP8SQ
LP_LRBUiiUlT7P8SQLP_AWBT7 + 0xBD8
0x09000000158EA694 sqlplrq__FP9sqeBsuEduP14SQLP_LOCK_INFO +
0x100
0x09000000158A3C7C
sqlrr_get_lock__FP8sqlrr_cbP14SQLP_LOCK_INFOUiPUi + 0x150
0x09000000157BEA30
sqlrlc_auth_rqst_loading_lock__FP8sqlrr_cbP19sqlrlc_entry_common
P14SQLP_LOCK_INFOPbPUsb + 0x1C8
0x09000000157BEC24
sqlrlc_auth_find_insert__FP8sqlrr_cbP21sqlrlc_auths_requiredP14S
QLP_LOCK_INFOPb + 0xF8
0x09000000169BA5DC
sqlrlc_rtn_get_auths__FP8sqlrr_cbP21sqlrlc_auths_requiredUiPUcN2
4 + 0x9A8
0x09000000186AD228
sqlrlc_rtn_request_auths__FP8sqlrr_cbP11sqlr_aainfoPUcUsT3sUcT3T
4T3T6N33P10sqlr_roles + 0x780
0x09000000181BE8B0
sqlra_is_rtn_auth_held__FP8sqlrr_cbP18sqlra_routine_infoP10sqlr_
rolesPUi + 0x108
0x09000000181BD6C4
sqlra_compare_env_routine_auths__FP8sqlrr_cbP16sqlra_cached_envi
T3Pi + 0x4D4
0x09000000181BD110
sqlra_compare_env_routine_auths__FP8sqlrr_cbP16sqlra_cached_envi
T3Pi@glue169A + 0x7C
0x090000001527E024
sqlra_hash_loc_env__FP8sqlrr_cbP14sqlra_cmpl_envP17sqlra_cached_
stmtibPP16sqlra_cached_envT6PUi + 0x3A0
0x090000001575EF10
sqlra_find_var_env__FP8sqlrr_cbP17sqlra_anchor_stmtP17sqlra_cach
ed_stmtP13sqlra_stmt_idUiP14sqlra_cmpl_env15sqlra_fill_modebT8Pi
T10_PP16sqlra_cached_envT10_ + 0x190
0x090000001575DF44
sqlra_find_var__FP8sqlrr_cbP17sqlra_cached_stmt13sqlra_stmt_idUi
T4PUcT4UsUcP14sqlra_cmpl_env15sqlra_fill_modePiiT12_N313_T12_P14
SQLP_LOCK_INFOPP16sqlra_cached_varT12_PUlb + 0x3CC
0x09000000157788FC sqlra_get_var__FP8sqlrr_cbiT2bPbT5 + 0x6D4
0x0900000016927484 sqlra_get_var__FP8sqlrr_cbiT2bPbT5@glue107F
+ 0x80
0x09000000155D59C8
sqlrr_process_execute_request__FP8sqlrr_cbib + 0x1658
the trace collected at the time of the issue, will have the
following entries in repeatable mode:
511377 0.115249574 | sqlrlc_auth_find_insert entry
[eduid 271486 eduname db2agent]
511382 0.115250455 | | sqlrlc_find_latch_anchor entry
[eduid 271486 eduname db2agent]
511390 0.115251523 | | | sqlra_hash_calc_obj entry
[eduid 271486 eduname db2agent]
511398 0.115252843 | | | | sqlra_hash_calc_stmt entry
[eduid 271486 eduname db2agent]
511411 0.115256156 | | | | sqlra_hash_calc_stmt exit
[rc = 0x00000038 = 56]
511416 0.115257187 | | | sqlra_hash_calc_obj exit [rc
= 0x00000038 = 56]
511431 0.115259000 | | | sqlrlc_find_entry entry
[eduid 271486 eduname db2agent]
511439 0.115261654 | | | | sqlrlc_rtn_find_entry entry
[eduid 271486 eduname db2agent]
511511 0.115274156 | | | | sqlrlc_rtn_find_entry exit
511527 0.115277039 | | | sqlrlc_find_entry exit
511537 0.115278576 | | sqlrlc_find_latch_anchor exit
511552 0.115281062 | | sqlrlc_update_lru entry [eduid
271486 eduname db2agent]
511570 0.115283156 | | sqlrlc_update_lru exit
511579 0.115285458 | sqlrlc_auth_find_insert exit
511586 0.115287890 | sqlrlc_rtn_check_auths_and_ts
entry [eduid 271486 eduname db2agent]
511594 0.115290281 | sqlrlc_rtn_check_auths_and_ts
exit
511600 0.115291093 sqlrlc_rtn_get_auths data [probe
859]
511611 0.115292968 | sqlrlc_auth_find_insert entry
[eduid 271486 eduname db2agent]
511619 0.115294812 | | sqlrlc_find_latch_anchor entry
[eduid 271486 eduname db2agent]
511625 0.115295937 | | | sqlra_hash_calc_obj entry
[eduid 271486 eduname db2agent]
511632 0.115296781 | | | | sqlra_hash_calc_stmt entry
[eduid 271486 eduname db2agent]
511642 0.115298718 | | | | sqlra_hash_calc_stmt exit
[rc = 0x00000037 = 55]
511650 0.115301375 | | | sqlra_hash_calc_obj exit [rc
= 0x00000037 = 55]
511655 0.115302896 | | | sqlrlc_find_entry entry
[eduid 271486 eduname db2agent]
511661 0.115304201 | | | | sqlrlc_rtn_find_entry entry
[eduid 271486 eduname db2agent]
511715 0.115316343 | | | | sqlrlc_rtn_find_entry exit
511722 0.115317681 | | | sqlrlc_find_entry exit
511731 0.115318937 | | sqlrlc_find_latch_anchor exit
511749 0.115323564 | | sqlrlc_update_lru entry [eduid
271486 eduname db2agent]
511768 0.115326656 | | sqlrlc_update_lru exit
511774 0.115327531 | sqlrlc_auth_find_insert exit
511787 0.115330587 | sqlrlc_rtn_check_auths_and_ts
entry [eduid 271486 eduname db2agent]
511795 0.115331761 | sqlrlc_rtn_check_auths_and_ts
exit
511806 0.115333906 sqlrlc_rtn_get_auths data [probe
859]
511820 0.115336281 | sqlrlc_auth_find_insert entry
[eduid 271486 eduname db2agent]
511829 0.115338875 | | sqlrlc_find_latch_anchor entry
[eduid 271486 eduname db2agent]
511833 0.115340375 | | | sqlra_hash_calc_obj entry
[eduid 271486 eduname db2agent]
511841 0.115341486 | | | | sqlra_hash_calc_stmt entry
[eduid 271486 eduname db2agent]
511847 0.115342843 | | | | sqlra_hash_calc_stmt exit
[rc = 0x00000035 = 53]
511855 0.115343746 | | | sqlra_hash_calc_obj exit [rc
= 0x00000035 = 53]
511864 0.115346250 | | | sqlrlc_find_entry entry
[eduid 271486 eduname db2agent]
511881 0.115348437 | | | | sqlrlc_rtn_find_entry entry
[eduid 271486 eduname db2agent]
511918 0.115361375 | | | | sqlrlc_rtn_find_entry exit
511932 0.115363593 | | | sqlrlc_find_entry exit
511938 0.115365589 | | sqlrlc_find_latch_anchor exit
511951 0.115367437 | | sqlrlc_update_lru entry [eduid
271486 eduname db2agent]
511961 0.115370871 | | sqlrlc_update_lru exit |
| Problem Summary: |
****************************************************************
* USERS AFFECTED: *
* All users on DB2 v97, v10.1, v10.5 and v11.1 *
****************************************************************
* PROBLEM DESCRIPTION: *
* See Error Description *
****************************************************************
* RECOMMENDATION: *
* Upgrade to DB2 v10.5 FP9 or V11.1 FP2. *
* *
* The fix on V10.1 can be obtained via special build if cant *
* be upgraded. *
**************************************************************** |
| Local Fix: |
As a temp workaround, if the eviction of entries was due to
catalog cache size, then catalog cache cane be increased:
db2 update db cfg for using catalogcache_sz |
| Solution |
|
| Workaround |
not known / see Local fix |
| BUG-Tracking |
forerunner : IT19939
follow-up : |
| Timestamps |
Date - problem reported :
Date - problem closed :
Date - last modified :
| 29.03.2017
30.03.2017
30.03.2017 |
| Problem solved at the following versions (IBM BugInfos) |
|
| Problem solved according to the fixlist(s) of the following version(s) |
