{"id":564,"date":"2009-01-20T18:07:08","date_gmt":"2009-01-20T16:07:08","guid":{"rendered":"http:\/\/www.ora-solutions.net\/web\/?p=564"},"modified":"2009-01-20T18:07:08","modified_gmt":"2009-01-20T16:07:08","slug":"session-waiting-for-enq-ro-fast-object-reuse-dbwr-process-spinning-on-cpu","status":"publish","type":"post","link":"https:\/\/www.ora-solutions.net\/web\/2009\/01\/20\/session-waiting-for-enq-ro-fast-object-reuse-dbwr-process-spinning-on-cpu\/","title":{"rendered":"Session waiting for “enq: RO – fast object reuse” – DBWR Process spinning on CPU"},"content":{"rendered":"

I have encountered the following problem on a 10.2.0.4 database on Linux x86_64 today:
\nA user session has been waiting for “enq: RO – fast object reuse” for almost 60 minutes while executing a “truncate table” SQL statement.<\/p>\n

SQL> select username, event, sql_id, taddr, last_call_et from v$session where sid = 234;<\/p>\n

USERNAME EVENT SQL_ID TADDR LAST_CALL_ET
\n———- —————————– ————- —————- ————
\nMD enq: RO – fast object reuse ljk299jlkj003 0000000153264570 3542<\/p>\n

SQL> select sql_text from v$sqlstats where sql_id = ‘ljk299jlkj003’;<\/p>\n

SQL_TEXT
\n————————————-
\ntruncate table tab1<\/p><\/blockquote>\n

The Session was blocked by the CKPT process:<\/p>\n

SQL> select * from dba_waiters;<\/p>\n

WAITING_SESSION HOLDING_SESSION LOCK_TYPE MODE_HELD MODE_REQUESTED LOCK_ID1 LOCK_ID2
\n————— ————— ————————– —————————————- —————————————- ———- ———-
\n 234 423 RO Row-S (SS) Exclusive 65573 1<\/p>\n

SQL> select sid, serial#, sql_id, last_call_et, machine, program, username from v$session where sid = 423;<\/p>\n

SID SERIAL# SQL_ID LAST_CALL_ET MACHINE PROGRAM
\n———- ———- ————- ———— —————- ——————————–
\n 423 1 4133636 ora-vm1.intra oracle@ora-vm1.intra (CKPT)\n<\/p><\/blockquote>\n

The checkpoint process was waiting for database writer DBWR process, which was spinning on one cpu:<\/p>\n

top<\/p>\n

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
\n10712 oracle 25 0 2201m 1.7g 1.7g R 99.5 21.7 108:18.03 oracle<\/p><\/blockquote>\n

PID 10712 maps to DBW0:<\/p>\n

[oracle@ora-vm1 ]$ ps -ef|grep 10712
\noracle 10712 1 0 2008 ? 03:23:05 ora_dbw0_MDDB01\n<\/p><\/blockquote>\n

mpstat<\/p>\n

Linux 2.6.9-78.ELsmp (ora-vm1.intra) 01\/20\/2009<\/p>\n

02:21:56 PM CPU %user %nice %system %iowait %irq %soft %idle intr\/s
\n02:21:57 PM all 49.75 0.00 0.00 0.00 0.00 0.00 50.25 1055.00
\n02:21:57 PM 0 0.00 0.00 0.00 0.00 0.00 0.00 100.00 1006.00
\n02:21:57 PM 1 100.00 0.00 0.00 0.00 0.00 0.00 0.00 49.00<\/p>\n

02:21:57 PM CPU %user %nice %system %iowait %irq %soft %idle intr\/s
\n02:21:58 PM all 50.75 0.00 0.00 0.50 0.00 0.00 48.76 1161.00
\n02:21:58 PM 0 1.00 0.00 0.00 1.00 0.00 0.00 98.00 1087.00
\n02:21:58 PM 1 100.00 0.00 0.00 0.00 0.00 0.00 0.00 74.00\n<\/p><\/blockquote>\n

The stack of dbw0 during the time showed these signatures:<\/p>\n

[oracle@ora-vm1 oracle]$ pstack 10712
\n#0 0x000000000074b7fb in kslfre ()
\n#1 0x00000000010ccc3b in kcbo_exam_buf ()
\n#2 0x00000000010d0d62 in kcbo_service_ockpt ()
\n#3 0x0000000001080cd7 in kcbbdrv ()
\n#4 0x00000000007ddcc2 in ksbabs ()
\n#5 0x00000000007e4b32 in ksbrdp ()
\n#6 0x0000000002efcb50 in opirip ()
\n#7 0x00000000012da326 in opidrv ()
\n#8 0x0000000001e62456 in sou2o ()
\n#9 0x00000000006d2555 in opimai_real ()
\n#10 0x00000000006d240c in main ()
\n[oracle@ora-vm1 oracle]$ pstack 10712
\n#0 0x000000000074b36d in kslfre ()
\n#1 0x00000000010cc203 in kcbo_write_process ()
\n#2 0x00000000010ce608 in kcbo_write_q ()
\n#3 0x0000000001080a6d in kcbbdrv ()
\n#4 0x00000000007ddcc2 in ksbabs ()
\n#5 0x00000000007e4b32 in ksbrdp ()
\n#6 0x0000000002efcb50 in opirip ()
\n#7 0x00000000012da326 in opidrv ()
\n#8 0x0000000001e62456 in sou2o ()
\n#9 0x00000000006d2555 in opimai_real ()
\n#10 0x00000000006d240c in main ()
\n[oracle@ora-vm1 oracle]$ pstack 10712
\n#0 0x00000000010ccb60 in kcbo_exam_buf ()
\n#1 0x00000000010d0d62 in kcbo_service_ockpt ()
\n#2 0x0000000001080cd7 in kcbbdrv ()
\n#3 0x00000000007ddcc2 in ksbabs ()
\n#4 0x00000000007e4b32 in ksbrdp ()
\n#5 0x0000000002efcb50 in opirip ()
\n#6 0x00000000012da326 in opidrv ()
\n#7 0x0000000001e62456 in sou2o ()
\n#8 0x00000000006d2555 in opimai_real ()
\n#9 0x00000000006d240c in main ()
\n[oracle@ora-vm1 oracle]$ pstack 10712
\n#0 0x00000000010d0da5 in kcbo_service_ockpt ()
\n#1 0x0000000001080cd7 in kcbbdrv ()
\n#2 0x00000000007ddcc2 in ksbabs ()
\n#3 0x00000000007e4b32 in ksbrdp ()
\n#4 0x0000000002efcb50 in opirip ()
\n#5 0x00000000012da326 in opidrv ()
\n#6 0x0000000001e62456 in sou2o ()
\n#7 0x00000000006d2555 in opimai_real ()
\n#8 0x00000000006d240c in main ()<\/p><\/blockquote>\n

A MetaLink Research for the term “kcbo_service_ockpt” leads to Bug 7376934, which is a duplicate of Bug 7385253 – DBWR IS CONSUMING HIGH CPU. <\/p>\n

Patch 7385253 is available for Linux x86_64, HP-UX, Solaris, AIX.
\nReference:
\nMetaLink Note 762085.1 – Subject: \t‘enq: RO – fast object reuse’ contention when gathering schema\/table statistics in parallel<\/p>\n","protected":false},"excerpt":{"rendered":"

I have encountered the following problem on a 10.2.0.4 database on Linux x86_64 today: A user session has been waiting for “enq: RO – fast object reuse” for almost 60 minutes while executing a “truncate table” SQL statement. SQL> select username, event, sql_id, taddr, last_call_et from v$session where sid = 234; USERNAME EVENT SQL_ID TADDR […]<\/p>\n","protected":false},"author":2,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_monsterinsights_skip_tracking":false,"_monsterinsights_sitenote_active":false,"_monsterinsights_sitenote_note":"","_monsterinsights_sitenote_category":0,"footnotes":""},"categories":[13,47,43,44,49,19,5,46,12],"tags":[],"class_list":["post-564","post","type-post","status-publish","format-standard","hentry","category-10g","category-bugs","category-hp-ux-unix-2","category-linux-unix-2","category-linux-itanium","category-metalink","category-oracle-database","category-solaris-unix-2","category-unix"],"aioseo_notices":[],"_links":{"self":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts\/564","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/users\/2"}],"replies":[{"embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/comments?post=564"}],"version-history":[{"count":5,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts\/564\/revisions"}],"predecessor-version":[{"id":569,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/posts\/564\/revisions\/569"}],"wp:attachment":[{"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/media?parent=564"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/categories?post=564"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.ora-solutions.net\/web\/wp-json\/wp\/v2\/tags?post=564"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}