Simple SQL with High Concurrency Wait Time (cursor: pin S wait on X) [message #518706] |
Fri, 05 August 2011 09:22 |
|
eclipsis
Messages: 14 Registered: May 2011
|
Junior Member |
|
|
Hello,
In our system, we have a PL/SQL process which runs to move data from a source table to a destination table. During the move, many validations and several calculations are performed. These validations and calculations mostly use smallish look-up tables. They either lookup a value based on key fields, or do a count to make sure a value is valid. I have checked the execution plan for these queries and they are all good. Most validation make use of only the index and don't even need to touch the data itself. All of the lookups/calculations also make use of the index.
We have 1000 partitions in the source and destination table. The above PL/SQL process takes the partition name as a parameter and processes the corresponding data. We run 30 of these jobs in parallel.
When I monitor these sessions, I see a significant amount of wait time between two wait events - "cursor: pin S wait on X" and "latch: cache buffers chains". I am focusing on the first as it has more time than the second.
Below is an example of one of the calculations. This is the SQL_TEXT from V$SQL:
SELECT col_name
FROM LDS_TABLE_NAME
WHERE key1 = SUBSTR (:B4 , 1, 3)
AND key2 = SUBSTR (:B3 , 1, 3)
AND key3 = :B2
AND :B1 BETWEEN EFF_DT AND DISC_DT
The query itself is not a problem. The plan is good (using index) and execution time is very good. But when 30 are running together, we start to see issues. As the processes are running, I can watch v$sql and see concurrency wait time increase as well as parses.
FETCHES EXECUTIONS END_OF_FETCH_COUNT PARSE_CALLS BUFFER_GETS CONCURRENCY_WAIT_TIME USER_IO_WAIT_TIME CPU_TIME
---------- ---------- ------------------ ----------- ----------- --------------------- ----------------- ----------
2112817 2112499 2112850 102 29784490 1507725 38037686 439643287
And run again about 60 seconds later I see
FETCHES EXECUTIONS END_OF_FETCH_COUNT PARSE_CALLS BUFFER_GETS CONCURRENCY_WAIT_TIME USER_IO_WAIT_TIME CPU_TIME
---------- ---------- ------------------ ----------- ----------- --------------------- ----------------- ----------
2277899 2277586 2277934 108 32105322 1607383 39232922 468924597
All the while, the resource utilization is very low, making this seem like a huge bottleneck. I think it comes down to the parsing - parsing causes one session to put a lock while the others wait. So the question is, why is this statement being parsed each time?
Any tips or suggestions are greatly appreciated!
|
|
|
|
|
|
|
|
|
Re: Simple SQL with High Concurrency Wait Time (cursor: pin S wait on X) [message #518739 is a reply to message #518719] |
Fri, 05 August 2011 17:00 |
cookiemonster
Messages: 13958 Registered: September 2008 Location: Rainy Manchester
|
Senior Member |
|
|
Number of executions between last 2 snaps = 12524058 - 2277586 = 10,246,472
Number of parses betweem last 2 snaps = 397 - 108 = 289
Number of execs per parse = 10246472 / 289 = 35455
You're hardly doing any parsing what so ever. Is there any evidence to prove that that's where the time is being spent?
Why don't you trace the session? It'll be more informative than what you're looking at.
|
|
|
Re: Simple SQL with High Concurrency Wait Time (cursor: pin S wait on X) [message #518752 is a reply to message #518739] |
Sat, 06 August 2011 01:49 |
John Watson
Messages: 8960 Registered: January 2010 Location: Global Village
|
Senior Member |
|
|
Like your other responders, I think you may be looking at the wrong thing. You said Quote:I see a significant amount of wait time between two wait events - "cursor: pin S wait on X" and "latch: cache buffers chains". The first is to do with mutexes, I can't make any suggestions there, but the cache buffers chains latch problem may be fixable.
Have you looked at bug 5918642 ?
There are also the parameters _db_block_hash_buckets and _db_block_hash_latches that you might want to research.
Or re-write your code to store the table in a variable, so each session scans it only once.
Any good?
Finally, can you post a statspack or AWR report, to show the evidence of the problem?
|
|
|
Re: Simple SQL with High Concurrency Wait Time (cursor: pin S wait on X) [message #518754 is a reply to message #518752] |
Sat, 06 August 2011 03:11 |
|
LNossov
Messages: 318 Registered: July 2011 Location: Germany
|
Senior Member |
|
|
Hello,
1. the bug 5918642 deals mainly with the other latch (simulator lru latch),
2. waits on "latch: cache buffers chains" causes the 30 processes, that access the same blocks in buffer cache,
3. defaults of "_" parameters, you mentioned, are in 10g high enough.
The problematic sql
- consumes more than 30 min. CPU,
- waits about 2 min. on io,
- waits on some concurrent event (possibly on latch) about 10 sec.
I think, it is clear, what you have to tune firstly.
I'm not sure, that just this sql causes a bad performance. As cookiemonster already suggested, eclipsis has to trace his process with event 10046 level 8 and upload the trace file.
Regards
Leonid
[Updated on: Sat, 06 August 2011 03:24] Report message to a moderator
|
|
|
|
|
|
|
Re: Simple SQL with High Concurrency Wait Time (cursor: pin S wait on X) [message #519062 is a reply to message #519003] |
Tue, 09 August 2011 03:35 |
John Watson
Messages: 8960 Registered: January 2010 Location: Global Village
|
Senior Member |
|
|
With regard to the AWR report, you can generate it now, no need to wait. Run the $ORACLE_HOME/rdbms/admin/awrrpt.sql script, and you'll be prompted to choose the days you are interested in, then the available snapshots (by default, every hour.) Choose two snapshots that bracket a time when this process running, generate the report, and post it here. Bertter generate both the html and the txt version.
|
|
|
|
|
|
|