DB2 - Problem description
Problem IT19946 | Status: Closed |
HIGH NUMBER OF CATCACHE LOCKS IMPACTING PERFORMANCE OF QUERIES | |
product: | |
DB2 FOR LUW / DB2FORLUW / A50 - 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 * **************************************************************** * PROBLEM DESCRIPTION: * * See Error Description * **************************************************************** * RECOMMENDATION: * * Upgrade to Db2 10.5 Fix Pack 9 or higher * **************************************************************** | |
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 <dbname> using catalogcache_sz <value> | |
Solution | |
First fixed in Db2 10.5 Fix Pack 9 | |
Workaround | |
not known / see Local fix | |
Timestamps | |
Date - problem reported : Date - problem closed : Date - last modified : | 29.03.2017 29.09.2017 29.09.2017 |
Problem solved at the following versions (IBM BugInfos) | |
9.0. | |
Problem solved according to the fixlist(s) of the following version(s) |