Job Queue Slave Process Encounters High Buffer Busy Waits
(Doc ID 2566973.1)
Last updated on JULY 20, 2024
Applies to:
Oracle Database - Enterprise Edition - Version 12.1.0.2 and laterInformation in this document applies to any platform.
Symptoms
You experience long wait times on wait event, 'buffer busy waits', by job queue slave processes (Jnnn). The process is waiting to update table, SYS.SCHEDULER$_JOB, with OBJ# specified in the WHERE clause (with SQL ID 'g4gp07gt2z920').
Diagnostics hang-manager file output may look similar to the following. Both job queue slave processes are attempting to update SYS.SCHEDULER$_JOB.
Short stack dump: ksedsts()+346<-ksdxfstk()+71<-ksdxcb()+912<-sspuser()+217<-__sighandler()<-__lll_lock_wait()+34<-00007F8B40B27AC0
.
.
.
HM: Current SQL: update sys.scheduler$_job set last_start_date = :1, running_instance = :2, running_slave = :3, job_status = :4 where obj# = :5 ◄◄◄ SQL ID 'g4gp07gt2z920'
.
.
.
----------------------------------------
SO: 0x2c83e6c40, type: 4, owner: 0x2c8050680, flag: INIT/-/-/-/0x00 if: 0x3 c: 0x3
proc=0x2c8050680, name=session, file=ksu.h LINE:15737, pg=1, conuid=0
(session) sid: 651 ser: 6624 trans: 0x2c7f803b0, creator: 0x2c8050680
flags: (0x41) USR/- flags2: (0x40009) -/-/INC
flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
DID: 0001-009D-0000062A0001-009D-00000629, short-term DID:
txn branch: (nil)
edition#: 0 user#/name: 0/SYS
oct: 6, prv: 0, sql: 0x52e097e18, psql: 0x52faf4718
stats: 0x2abac85d0, PX stats: 0x110a9884
service name: SYS$USERS
client details:
O/S info: user: oracle, term: UNKNOWN, ospid: 64791_32737
machine: fs01dbadm01.state.fl.us program: oracle@fs01dbadm01.state.fl.us (J002) ◄◄◄ Job queue slave
Current Wait Stack:
Not in wait; last wait ended 7 min 34 sec ago ◄◄◄ Either running on a CPU, or waiting to be assigned to a CPU.
There are 1 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 93, ser: 57345
wait event: 'buffer busy waits'
p1: 'file#'=0x1
p2: 'block#'=0x4699
p3: 'class#'=0x1
row_wait_obj#: 8877, block#: 18073, row#: 0, file# 1
min_blocked_time: 427 secs, waiter_cache_ver: 10225 ◄◄◄ Another job queue slave is waiting for busy buffer for at least 7 mins.
Wait State:
fixed_waits=0 flags=0x20 boundary=(nil)/-1
Session Wait History:
elapsed time of 7 min 34 sec since last wait
0: waited for 'enq: IV - contention'
type|mode=0x49560005, id1=0x53594e43, id2=0xb7
wait_id=37 seq_num=38 snap_id=1
wait times: snap=0.000297 sec, exc=0.000297 sec, total=0.000297 sec
wait times: max=infinite
wait counts: calls=2 os=2
occurred after 0.000080 sec of elapsed time
.
.
.
.
.
.
HM: Current SQL: update sys.scheduler$_job set last_start_date = :1, running_instance = :2, running_slave = :3, job_status = :4 where obj# = :5 ◄◄◄ SQL ID 'g4gp07gt2z920'
.
.
.
----------------------------------------
SO: 0x2c83e6c40, type: 4, owner: 0x2c8050680, flag: INIT/-/-/-/0x00 if: 0x3 c: 0x3
proc=0x2c8050680, name=session, file=ksu.h LINE:15737, pg=1, conuid=0
(session) sid: 651 ser: 6624 trans: 0x2c7f803b0, creator: 0x2c8050680
flags: (0x41) USR/- flags2: (0x40009) -/-/INC
flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
DID: 0001-009D-0000062A0001-009D-00000629, short-term DID:
txn branch: (nil)
edition#: 0 user#/name: 0/SYS
oct: 6, prv: 0, sql: 0x52e097e18, psql: 0x52faf4718
stats: 0x2abac85d0, PX stats: 0x110a9884
service name: SYS$USERS
client details:
O/S info: user: oracle, term: UNKNOWN, ospid: 64791_32737
machine: fs01dbadm01.state.fl.us program: oracle@fs01dbadm01.state.fl.us (J002) ◄◄◄ Job queue slave
Current Wait Stack:
Not in wait; last wait ended 7 min 34 sec ago ◄◄◄ Either running on a CPU, or waiting to be assigned to a CPU.
There are 1 sessions blocked by this session.
Dumping one waiter:
inst: 1, sid: 93, ser: 57345
wait event: 'buffer busy waits'
p1: 'file#'=0x1
p2: 'block#'=0x4699
p3: 'class#'=0x1
row_wait_obj#: 8877, block#: 18073, row#: 0, file# 1
min_blocked_time: 427 secs, waiter_cache_ver: 10225 ◄◄◄ Another job queue slave is waiting for busy buffer for at least 7 mins.
Wait State:
fixed_waits=0 flags=0x20 boundary=(nil)/-1
Session Wait History:
elapsed time of 7 min 34 sec since last wait
0: waited for 'enq: IV - contention'
type|mode=0x49560005, id1=0x53594e43, id2=0xb7
wait_id=37 seq_num=38 snap_id=1
wait times: snap=0.000297 sec, exc=0.000297 sec, total=0.000297 sec
wait times: max=infinite
wait counts: calls=2 os=2
occurred after 0.000080 sec of elapsed time
.
.
.
Changes
The instance-wide value of THREADED_EXECUTION is TRUE (whereas its default value is FALSE).
Cause
To view full details, sign in with your My Oracle Support account. |
|
Don't have a My Oracle Support account? Click to get started! |
In this Document
| Symptoms |
| Changes |
| Cause |
| Solution |