首页 » ORACLE 9i-23ai » Troubleshooting Oracle 12.1 ‘enq: TC – contention’ wait event and related issues
Troubleshooting Oracle 12.1 ‘enq: TC – contention’ wait event and related issues
Recently, a customer’s Oracle database RMAN backup job failed. When doing a full backup, it took a long time to complete. After checking the database, it was found that the backup process was waiting for ‘enq: TC – contention’. The environment was Oracle 12.1 2-nodes RAC. I would like to record this problem.
Check wait event
SQL> @ace
last_call
USERNAME SID EVENT MACHINE MODULE STATUS et SEQ# SQL_ID WAI_SECINW ROW_WAIT_OBJ# SQLTEXT BS CH# OSUSER HEX
---------- ---------- -------------------- ---------- -------------------- ------- --------- ---------- --------------- ---------- ------------- ------------------------------ ---------- ---- ---------- ----------
SYS 287 enq: TC - contention anbob1 backup incr datafile ACTIVE 21383 480 0:21382 -1 1:3196 oracle
SYS 6477 enq: TC - contention anbob1 backup incr datafile ACTIVE 39592 483 0:39592 -1 1:3196 oracle
SYS 9028 enq: TC - contention anbob1 backup incr datafile ACTIVE 84355 360 0:84355 -1 1:3196 oracle
SYS 2925 enq: TC - contention anbob1 backup incr datafile ACTIVE 95563 368 0:95562 -1 1:3196 oracle
SYS 5770 enq: TC - contention anbob1 backup incr datafile ACTIVE 596167 363 0:596167 -1 1:3196 oracle
Note:
blocking session instance 1 sid 3196, and these waited session longest waw blocked 596167 seconds.
Blocking session
SQL> select sid,username,machine,event,STATUS,PROGRAM,last_call_et ,blocking_session from v$session where sid=3196;
last_call
SID USERNAME MACHINE EVENT STATUS PROGRAM et BLOCKING_SESSION
---------- ---------- ---------- -------------------- ------- -------------------------------- --------- ----------------
3196 anbob1 rdbms ipc message ACTIVE oracle@anbob1 (CKPT) 27248883
Note:
The blockings session CKPT（checkpoint background process）
What is enq: TC – contention?
sys@ORA19C 22:30:19> @sed "tc " Show wait event descriptions matching tc .. EVENT# EVENT_NAME WAIT_CLASS PARAMETER1 PARAMETER2 PARAMETER3 ENQUEUE_NAME REQ_REASON REQ_DESCRIPTION ------ -------------------------- - -------------------- ------------------------- ------------------------- ------------------------- ------------------------------ -------------------------------- ---------------------------------------------------------------------------------------------------- 777 enq: TC - contention Other name|mode checkpoint ID 0 Tablespace Checkpoint contention Lock held to guarantee uniqueness of a tablespace checkpoint 778 enq: TC - contention2 Other name|mode checkpoint ID 0 Tablespace Checkpoint contention2 Lock of setup of a unqiue tablespace checkpoint in null mode
Note:
tablesapce checkpoint is requested during Full backup.
CHECK I/O
$ iostat -d 1 5 System configuration: lcpu=128 drives=23 paths=170 vdisks=0 Disks: % tm_act Kbps tps Kb_read Kb_wrtn hdisk1 2.0 136.0 7.0 0 136 hdisk0 2.0 136.0 7.0 0 136 hdisk17 3.0 292.0 93.0 0 292 ... hdisk10 0.0 0.0 0.0 0 0 hdisk22 99.0 764.0 191.0 424 340 hdisk21 0.0 1.0 3.0 1 0 hdisk20 0.0 1.0 3.0 1 0 .. Disks: % tm_act Kbps tps Kb_read Kb_wrtn hdisk1 0.0 0.0 0.0 0 0 hdisk0 0.0 0.0 0.0 0 0 hdisk17 2.0 364.0 114.0 0 364 ... hdisk10 0.0 16.0 1.0 16 0 hdisk22 100.0 788.0 197.0 436 352 hdisk21 0.0 1.0 3.0 1 0 ..
Note:
the disk hdisk22 is busy now. but ..IO not hang.
Manual checkpoint
SQL> alter system checkpoint ; completed.
Note:
checkpoint work fine
Wait session call stack
SQL> @usid 9028 USERNAME SID AUDSID OSUSER MACHINE PROGRAM SPID OPID CPID SQL_ID HASH_VALUE LASTCALL STATUS SADDR PADDR TADDR LOGON_TIME ----------------------- -------------- ----------- ---------------- ------------------ -------------------- -------------- ------ -------------------------------------------------------------------- --------------- ----------- ---------- ------- ---------------- ---------------- -------------------------------- -------------- SYS '9028,39170' 4294967295 oracle anbob1 (TNS V1-V3) 61604538 895 12387110 0 84737 ACTIVE 0700011DB2D65080 0700011DE204B9E0 24/10/30 22:40 SQL> oradebug setorapid 895 Oracle pid: 895, Unix process pid: 61604538, image: oracle@mesdb1 SQL> oradebug short_stack; ksedsts()+712<-ksdxfstk()+44<-ksdxcb()+896<-sspuser()+220<-__sighandler()<-thread_wait()+556<-sskgpwwait()+56<-skgpwwait()+268<-ksliwat()+8212<-kslwaitctx()+764<-kjuscv_wait()+1720<-kjuscv()+2288<-ksipcon()+1340<-ksqcmi()+2964<-ksqcnv()+752<-ksqcov()+112<-kcvgcf()+628<-krbckf()+744<-krbbFileCkpt()+1108<-krbbpcint()+11692<-krbbpc()+4260<-krbibpc()+1688<-pevm_icd_call_common()+460<-pfrinstr_ICAL()+136<-pfrrun_no_tool()+92<-pfrrun()+4940<-plsql_run()+752<-pricar()+556<-pricbr()+600<-prient2()+1212<-prient()+2212<-kkxrpc()+1140<-kporpc()+392<-opiodr()+948<-ttcpip()+844<-opitsk()+8740<-opiino()+2968<-opiodr()+948<-opidrv()+1044<-sou2o()+240<-opimai_real()+448<-ssthrdmain()+452<-main()+208<-__start()+112 SQL> oradebug short_stack; ksedsts()+712<-ksdxfstk()+44<-ksdxcb()+896<-sspuser()+220<-__sighandler()<-thread_wait()+556<-sskgpwwait()+56<-skgpwwait()+268<-ksliwat()+8212<-kslwaitctx()+764<-kjuscv_wait()+1720<-kjuscv()+2288<-ksipcon()+1340<-ksqcmi()+2964<-ksqcnv()+752<-ksqcov()+112<-kcvgcf()+628<-krbckf()+744<-krbbFileCkpt()+1108<-krbbpcint()+11692<-krbbpc()+4260<-krbibpc()+1688<-pevm_icd_call_common()+460<-pfrinstr_ICAL()+136<-pfrrun_no_tool()+92<-pfrrun()+4940<-plsql_run()+752<-pricar()+556<-pricbr()+600<-prient2()+1212<-prient()+2212<-kkxrpc()+1140<-kporpc()+392<-opiodr()+948<-ttcpip()+844<-opitsk()+8740<-opiino()+2968<-opiodr()+948<-opidrv()+1044<-sou2o()+240<-opimai_real()+448<-ssthrdmain()+452<-main()+208<-__start()+112 SQL> oradebug short_stack; ksedsts()+712<-ksdxfstk()+44<-ksdxcb()+896<-sspuser()+220<-__sighandler()<-thread_wait()+556<-sskgpwwait()+56<-skgpwwait()+268<-ksliwat()+8212<-kslwaitctx()+764<-kjuscv_wait()+1720<-kjuscv()+2288<-ksipcon()+1340<-ksqcmi()+2964<-ksqcnv()+752<-ksqcov()+112<-kcvgcf()+628<-krbckf()+744<-krbbFileCkpt()+1108<-krbbpcint()+11692<-krbbpc()+4260<-krbibpc()+1688<-pevm_icd_call_common()+460<-pfrinstr_ICAL()+136<-pfrrun_no_tool()+92<-pfrrun()+4940<-plsql_run()+752<-pricar()+556<-pricbr()+600<-prient2()+1212<-prient()+2212<-kkxrpc()+1140<-kporpc()+392<-opiodr()+948<-ttcpip()+844<-opitsk()+8740<-opiino()+2968<-opiodr()+948<-opidrv()+1044<-sou2o()+240<-opimai_real()+448<-ssthrdmain()+452<-main()+208<-__start()+112 kjuscv_wait()+1720 kernel lock management global enqueue service synchronous convert a lock [partial hit for: kjuscv ] kjuscv()+2288 kernel lock management global enqueue service synchronous convert a lock ksipcon()+1340 kernel service instance locking IPC convert a group lock ksqcmi()+2964 kernel service enqueue change lock mode internal ksqcnv()+752 kernel service enqueue convert an enqueue's mode ksqcov()+112 kernel service enqueue convert an enqueue's mode kcvgcf()+628 kernel cache recovery [partial hit for: kcv ] krbckf()+744 kernel redo backup/restore controlfile [partial hit for: krbc ] krbbFileCkpt()+1108 kernel redo backup/restore creation of a backuppiece [partial hit for: krbb ] krbbpcint()+11692 kernel redo backup/restore creation of a backuppiece piece create [partial hit for: krbbpc ] krbbpc()+4260 kernel redo backup/restore creation of a backuppiece piece create krbibpc()+1688 kernel redo backup/restore dbms_backup_restore package DBMS_BACKUP_RESTORE.KRBIBPC BACKUPPIECECREATE pevm_icd_call_common()+460 PLSQL code execution virtual machine [partial hit for: pevm ] pfrinstr_ICAL()+136 PLSQL interpeter runtime instruction? [partial hit for: pfrinstr ]
Find bugs
Rman Backup on 12.1.0.2 Hangs on Enq: TC – Contention (Doc ID 2379088.1)
Bug 26951406 – CKPT STUCK ,BLOCKING RMAN BACKUPS Closed as Duplicate of Unpublished BUG 27679641.
As a Workaround you can set the following parametersALTER SYSTEM SET db_lost_write_protect='TYPICAL' SCOPE=BOTH;However, this parameter will enable lost write protection and increase the size of the archive log. In addition, although the memory level can be changed, production must be restarted. For RAC, rolling restart is possible.
DB Alert log
— no error but repeat print the below message
Tracing is auto disabled for DB Writer: 7 at ts: 1730383269 Tracing is auto disabled for DB Writer: 5 at ts: 1730383269 Tracing is auto disabled for DB Writer: 15 at ts: 1730383269 Tracing is auto disabled for DB Writer: 10 at ts: 1730383269 Tracing is auto disabled for DB Writer: 1 at ts: 1730383269 Tracing is auto disabled for DB Writer: 12 at ts: 1730383269 Tracing is auto disabled for DB Writer: 0 at ts: 1730383269 Tracing is auto disabled for DB Writer: 2 at ts: 1730383269 Tracing is auto disabled for DB Writer: 4 at ts: 1730383269 Tracing is auto disabled for DB Writer: 13 at ts: 1730383269 Tracing is auto disabled for DB Writer: 14 at ts: 1730383269 Tracing is auto disabled for DB Writer: 8 at ts: 1730383269 Tracing is auto disabled for DB Writer: 6 at ts: 1730383269 Tracing is auto disabled for DB Writer: 9 at ts: 1730383269 Tracing is auto enabled for DB Writer: 8 at ts: 1730383269
Note:
that’s Another bug. Bug 22864300 – POOR RUNTIME PERFORMANCE DUE TO: STALL_WRITE_CHECK: DBWR TRACING IS AUTO ENABLED
Soulution
Set the following SQL> alter system set "_dbwr_stall_write_detection_interval" = 0; - Workaround is valid only when too much dbwr tracing starting with string "stall_write_check:" - other relevant underscore parameter that can also auto enable dbwr tracing is "_dbwr_nowrite_tracing_interval"
db_lost_write_protect Parameter
SQL> show parameter lost NAME TYPE VALUE ------------------------------------ ---------------------- ------------------------------ db_lost_write_protect string NONE ALTER SYSTEM SET db_lost_write_protect='TYPICAL' SCOPE=BOTH; -- restart instance
Start fail instance with ORA-29707 _lm_use_tx_tsn
SQL>shutdown immeidate SQL>startup ORA-29707: inconsistent value 0 for initialization parameter _lm_use_tx_tsn with other instances $ srvctl start instance -d anbob -i p1anbob1 PRCR-1013 : Failed to start resource ora.anbob.db PRCR-1064 : Failed to start resource ora.anbob.db on node anbob1 CRS-5017: The resource action "ora.anbob.db start" encountered the following error: ORA-29707: inconsistent value 0 for initialization parameter _lm_use_tx_tsn with other instances . For details refer to "(:CLSN00107:)" in "/oracle/app/gridbase/diag/crs/anbob1/crs/trace/crsd_oraagent_oracle.trc".
Note：
DB parameter was adjusted before, but it was not restarted. This parameter does not support rolling restart. You need to roll back the configuration of the relevant parameters before. like “_gc_undo_affinity” “_gc_policy_time” “undo_management” “_lm_drm_disable”
the case is “_lm_drm_disable=7” modified To disable DRM not restart, Reset parameter on surviving node.
SQL> alter system reset "_lm_drm_disable";
— work fine.
微信扫一扫，打赏作者吧～
目前这篇文章还没有评论(Rss)