gc buffer busy acquire vs release
Posted by Riyaj Shamsudeen on April 19, 2012
Last week (March 2012), I was conducting Advanced RAC Training online. During the class, I was recreating a ‘gc buffer busy’ waits to explain the concepts and methods to troubleshoot the issue.
Definitions
Let’s define these events first. Event ‘gc buffer busy’ event means that a session is trying to access a buffer,but there is an open request for Global cache lock for that block already, and so, the session must wait for the GC lock request to complete before proceeding. This wait is instrumented as ‘gc buffer busy’ event.
From 11g onwards, this wait event is split in to ‘gc buffer busy acquire’ and ‘gc buffer busy release’. An attendee asked me to show the differentiation between these two wait events. Fortunately, we had a problem with LGWR writes and we were able to inspect the waits with much clarity during the class.
Remember that Global cache enqueues are considered to be owned by an instance. From 11g onwards, gc buffer busy event differentiated between two cases:
- If existing GC open request originated from the local instance, then current session will wait for ‘gc buffer busy acquire’. Essentially, current process is waiting for another process in the local instance to acquire GC lock, on behalf of the local instance. Once GC lock is acquired, current process can access that buffer without additional GC processing (if the lock is acquired in a compatible mode).
- If existing GC open request originated from a remote instance, then current session will wait for ‘gc buffer busy release’ event. In this case session is waiting for another remote session (hence another instance) to release the GC lock, so that local instance can acquire buffer.
Example
Following output should show the differentiation with much clarity.
Notice that SID 53, instance is has open GC request for the block File #10, block #56051(line #1 in the output) and the session is waiting for ‘gc current request’ (which is a placeholder event, btw). All processes requesting an access to this block in instance 1 waits for ‘gc buffer busy acquire’. Similarly, all processes waiting for the block access in instance #2 is waiting for ‘gc buffer busy release’. Essentially, instance 1 sessions are waiting for local instance to acquire the GC lock, and instance 2 sessions are waiting for instance 1 to release the GC lock. Of course, LGWR is completely stuck in this case and so, Global cache layer is also nearly frozen.
INST_ID SID EVENT USERNAME STATE WIS P1_P2_P3_TEXT ------- ------ ----------------------- ---------- -------- ------------------------------- 1 53 gc current request SYS WAITING 26 file# 10-block# 560651-id# 16777217 1 40 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 60 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 59 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 58 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 56 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 55 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 54 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 53 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 1 48 gc buffer busy acquire SYS WAITING file# 10-block# 560651-class# 1 2 1 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 68 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 65 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 64 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 69 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 57 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 43 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 36 gc buffer busy release SYS WAITING file# 10-block# 560651-class# 1 2 47 log file sync SYS WAITING 22 buffer# 4450-sync scn 30839721- 0
In summary, this differentiation is useful. In most cases, ‘gc buffer busy’ is a symptom and so, in this example, I would review instance 1 closely since the waits are ‘gc buffer busy acquire’ in that instance and most probably, I would quickly start to diagnose session with sid=53 @inst=1
Sam said
very nice explanation … thanks
Bhaskar said
Good explanation — Thanks
Prashant Nair said
Great Explanation.. Thanks
swapnil mhetre said
Good Explanation. Thanks
sravya said
Good explanation sir!! Thanks
Bhavani said
very useful information and nice explanation
Gopal Seethepalli said
Another excellent article by Riyaj
Riyaj Shamsudeen said
Gopal
Thanks for visiting my blog.
ashwin said
Riyaj.
I read your blogs regularily and like them immensely… thanks for all those..
sorry but this one does not look to be true.. I am looking at an ash dump now from a instance where i see both xxrelease and xxacquire for a given sql_id and all 3 sets (sessions waiting, session blocking XXrelease and sessions blocking XXXacquire are from same inst). I can email u the spool file if u r interested.
Riyaj Shamsudeen said
Ashwin
Thanks for reading my blog. However, I think, you are looking at the sql_ids, however, you should look at the p1, p2, p3 values in ASH to see if the sessions are accessing the same block. My guess is that even though they are executing the same SQL statement, they are accessing different blocks.
Yes, please send me ASHDUMP if you can.
Thanks
Sreekumar said
well defined!!
hamdi özdere said
Hi,
Thanks for writing well. Good job (Adamın dibisin, helal olsun)
Andrea said
I really appreciated your explanation
oliseh said
Hi,
Can we manually simulate gc buffer busy acquire /release event ?
Riyaj Shamsudeen said
Yes, you can pstop the LGWR process in a 3 second loop while there is activity in the database to simulate the problem.
Raghu said
Riyaj,
Great Explanation. But how do we over come this situation when this buffer busy happens ?
roblesmichael17@gmail.com said
Riyaj, a good explanation. which would be the solution?
Ganesh said
Riyaj
Great explanation. Thanks for sharing your knowledge
Jayanth said
its good explanation.
can this article have more info on different ways to resolve would be much nice.
Thanks
Jay
Montaz anten Gorzow said
wohh just what I was looking for, regards for putting up.
Saibal Ghosh said
Riyaj, I suggest you have a look at this. It isn’t even funny: https://rajat1205sharma.wordpress.com/2015/03/31/gc-buffer-busy-acquire-vs-gc-buffer-busy-release/comment-page-1/#comment-332
gc buffer busy | Oracle Scratchpad said
[…] One of these cases is reported as “gc buffer busy acquire”, the other as a “gc buffer busy release” – and I always have to check which is which. I think I usually get it right first time when I see it, but I always manage to convince myself that I might have got it wrong and end up searching the internet for Riyaj Shamsudeen’s blog posting about it. […]
PP said
Hi Riyaz,
I am getting gc buffer busy acquire/release, gc current block busy,gc cr block lost ,gc current block lost , I had tried to increasing the Hash partition from 32 to 128 with table and indexes still I am getting the same wait event
infact I tried to move table on 4k block size where only insert operation was performing still I am unable to reduce the elapsed on insert statement which taking ~ 80ms,
Currently I am trying to insert around 2300000 insert in 15mins and getting above wait event after partitioning table and indexes and moved table on 4k block size from 8k block.
Wait
Event
Wait Time
Summary Avg Wait Time
I#
Class
Event
Waits
%Timeouts
Total(s)
Avg Wait
%DB time
Avg
Min
Max
Std Dev
Cnt
* Cluster gc current block busy 6,263,639 0.00 77,877.24 12.43ms 24.95 12.43ms 12.26ms 12.61ms 251.56us 2
*
Cluster gc cr block 2-way 4,872,185 0.00 53,875.64 11.06ms 17.26 11.05ms 10.94ms 11.16ms 150.65us 2
*
Cluster gc buffer busy acquire 821,191 0.00 44,797.36 54.55ms 14.35 55.63ms 46.84ms 64.42ms 12.44ms 2
*
DB CPU 40,592.59 13.00 2
*
Commit log file sync 6,138,946 0.00 20,695.50 3.37ms 6.63 3.60ms 2.79ms 4.41ms 1.15ms 2
*
Cluster gc current grant busy 1,184,365 0.00 20,572.83 17.37ms 6.59 17.02ms 12.65ms 21.40ms 6.18ms 2
*
Cluster gc cr block lost 23,158 0.00 13,264.09 572.76ms 4.25 673.78ms 572.57ms 774.98ms 143.12ms 2
*
Cluster gc current block 2-way 1,056,587 0.00 10,979.44 10.39ms 3.52 10.37ms 10.08ms 10.65ms 402.33us 2
*
Cluster gc current block lost 17,603 0.00 10,089.55 573.17ms 3.23 627.71ms 573.09ms 682.33ms 77.24ms 2
*
Cluster gc cr block busy 299,299 0.00 4,639.56 15.50ms 1.49 16.37ms 13.64ms 19.11ms 3.87ms 2