Buffered Message Dequeue Intermittently Slow when using a Correlation identifier (Doc ID 1314857.1)

Last updated on APRIL 19, 2011

Applies to:

Oracle Server - Enterprise Edition - Version: 10.2.0.4 to 11.2.0.2 - Release: 10.2 to 11.2
Information in this document applies to any platform.

Symptoms

Intermittently a dequeue session using a correlation identifier and a finite wait time will not be notified of a buffered message which has been enqueued while it has been waiting.

The message is dequeued at the end of the wait period. This only occurs for 1 or 2 messages out of 100.

Tracing with event '10852 trace name context forever, level 95' you see the following for a problem message

*** ACTION NAME:(dequeue28) 2009-04-30 15:18:57.994
*** MODULE NAME:(demo server) 2009-04-30 15:18:57.994
EXEC #2:c=0,e=39,p=0,cr=0,cu=3,mis=0,r=1,dep=1,og=2,tim=2523882406379
XCTEND rlbk=0, rd_only=0
EXEC #4:c=0,e=36,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=0,tim=2523882406474
kwqidlspdp: Enter
EXEC #6:c=0,e=45,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=2523882406653
FETCH #6:c=0,e=60,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=2523882406733
EXEC #6:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=2523882406834
FETCH #6:c=0,e=63,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=2523882406916
04/30/2009 15:18:57
kwqidexfcy - begin while loop wait 3000
kwqidexfcy waiting at queue 24441 itime 1000
kwqidexfcy queue 24441 count 0
kwqidexfcy: row locked - N
kwqidexfcy: sleeping ... enqueue_count 0
*** 2009-04-30 15:19:08.023
kwqidexfcy waiting at queue 24441 itime 1000
kwqidexfcy queue 24441 count 0
kwqidexfcy: row locked - N
kwqidexfcy: sleeping ... enqueue_count 0
*** 2009-04-30 15:19:18.053
kwqidexfcy waiting at queue 24441 itime 994
kwqidexfcy queue 24441 count 0
kwqidexfcy: row locked - N
kwqidexfcy: sleeping ... enqueue_count 0
EXEC #6:c=0,e=103,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=2523911732405
FETCH #6:c=0,e=343,p=0,cr=0,cu=0,mis=0,r=1,dep=1,og=4,tim=2523911732781
kwqidexfcy : found a message after 3003 centiseconds posted=0 ecnt_chg=0
kwqidexfcy: Initial wait time = 30 sec, total wait time = 30 sec
total wait time = 3003 centisec, new wait time = 0 sec

So the dequeue session waits because it believes no messages have been enqueued when there is in fact an IN_MEMORY message waiting to be dequeued.

The issue does not appear to reproduce when a correlation identifier is not used.

Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms