By Gints Plivna
What are long running operations and how to monitor them?
There is a dynamic performance view v$session_longops that is populated for many long running operations in Oracle. The primary criterion for any operation to appear in v$session_longops is to run more than 6 seconds. Although this isn’t the only criterion as well as not all operations that take more than 6 seconds are shown in this view. For example one can find hash joins in v$session_longops, but you won’t find there nested loop joins even if they are longer than 6 seconds and are joining very big data sets.
Some tools are showing long running operations graphically, so that one doesn’t need to query v$session_longops directly but tool is doing it for you.
Figure 1 Long operation by Oracle Enterprise Manager 9.2.0
Figure 2 Long operations by Oracle Application Express 2.1.
Of course there is always possibility to get necessary information straight from the view v$session_longops. In the examples given for this paper I’ve mostly used following query to get the most recent info from v$session_longops:
select * from (
select opname, target, sofar, totalwork,
units, elapsed_seconds, message
from v$session_longops order by start_time desc)
where rownum <=1;
On a busy server one would like to add filter on sid and serial# in the inner query to get the info only about the necessary session and the query is as follows:
select * from (
select opname, target, sofar, totalwork,
units, elapsed_seconds, message
from v$session_longops
where sid = and serial# =
order by start_time desc)
where rownum <=1;
One of the most important things when one is monitoring long running operations is to remember that Oracle considers all of them to be linear i.e. estimated time remaining (column TIME_REMAINING) is:
- inversely proportional to work already done (column SOFAR) and
- directly proportional to already spent seconds for work (column ELAPSED_SECONDS) and
- directly proportional to remaining work i.e. difference between all work (column TOTALWORK) and work already done (column SOFAR).
So the formula is 
After calculation TIME_REMAINING is rounded to the whole number. Of course in the real life not all things are linear because of various workloads and various works to be done and therefore expectations may be sometimes too optimistic as well as pessimistic. See example in chapter Linear prediction may be wrong.
Built in types of long operations
Each new version of Oracle adds several new types of built in long operations that are shown in v$session_longops. Some of them are:
- Table scan;
- Index Fast Full Scan;
- Hash join;
- Sort/Merge;
- Sort Output;
- Rollback;
- Gather Table's Index Statistics.
In next chapters I’ll look deeper into first three of the above listed types.
Table scan
Table scan is one of the most common long operations. It is shown only when done via FULL SCAN and is measured in database blocks occupied by the table.
Work behind the scenes
Actually Table scan may hide many other operations behind the scenes, therefore don’t be surprised if it takes very long time according to v$session_longops. Some of the examples are as follows (Example for each of the following bullet can be found here VariousTableScans.txt):
- Simple query scanning all the rows in the table;
- Query with a filter;
- Creation of an index and table scan to gather necessary info for the index;
- Alter table column from NULL to NOT NULL;
- Query with join where outer table is accessed via FULL SCAN and inner table is joined using NESTED LOOPS join, so table scan actually includes a hidden join;
- A cursor in PL/SQL that does a full scan on the table but inside the cursor the possibilities to do something are infinite.
All above statements according to v$session_longops are doing the same amount of work i.e. scanning 94577 blocks of the table BIG, but the time taken as well as the total work done is rather different.
10 000 database block threshold
Besides criterion that Table scan has to run more than 6 seconds there is one another criterion that is not so widely known – table has to occupy at least 10000 database blocks. Table scan has to satisfy BOTH criteria to show up in v$session_longops i.e. if the table has less than 10000 blocks but table scan runs more than 6 seconds that’s not enough.
Following example (full listing in 10000BlocksLongops.txt) illustrates this requirement.
1) Table BIG is created from dba_source in tablespace with segment space management set to manual to avoid any automatic block assignment for table.
2) To boost up the time of full scan index on two columns owner, name is created and table BIG is joined to itself using nested loops join.
3) To quickly fill up necessary blocks only one row into table is inserted and then issued command minimize rows_per_block.
4) Insert of 19987 rows fills up 9995 blocks.
5) Now following query is executed:
select /*+ full(a) use_nl(a, b) */ count(distinct a.line) from big a, big b
where a.owner = b.owner
and a.name = b.name;
It takes 41.68 seconds to run but there isn't any corresponding entry in v$session_longops.
6) Now two more rows are inserted and gathering table statistics approves that table now takes up 10 000 blocks (On XE I needed to insert only one additional row, therefore I tried to insert row after row).
7) The same query as in paragraph 5) is executed again.
Now it takes 41.48 seconds and one can see corresponding entry in v$session_longops.
Index Fast Full Scan
Index Fast Full Scan is one of the index access paths used when all the information can be gathered from index instead of scanning the entire table.
1 000 database block threshold
Index FFS as well as Table Scans have another criterion for showing up in v$session_longops. Index has to occupy at least 1000 blocks i.e. 10 times less than threshold for Table Scans.
Following example (full listing in 1000IndexFFSLongops.txt) illustrates this requirement.
1) Table BIG1 is created from dba_source in tablespace with segment space management set to manual to avoid any automatic block assignment for table. To make easier calculation index organized table is used.
2) To boost up the time of index fast full scan table BIG1 is joined to itself.
3) There isn’t possibility to use clause minimize rows_per_block for indexes, so an approximate number of rows should be found to fill up necessary blocks.
4) Insert of 82150 rows fills up 993 leaf blocks and index has bevel 2.
5) Now following query is executed:
select count(distinct a.line) from big1 a, big1 b
where a.owner = b.owner
and a.name = b.name
/
It takes 2 minutes and 28.68 seconds to run but there isn't any corresponding entry in v$session_longops.
6) Table is dropped and 50 rows more are inserted than previously. It fills up one more leaf block i.e. 994 leaf blocks.
7) The same query as in 5) is executed again.
8) Now it takes 2 minutes 26.37 seconds and one can see corresponding entry in v$session_longops showing Index Fast Full Scan over 1000 blocks taking 147 seconds.
Hash join
Hash joins are usually used joining large data sets. The performance of hash joins strongly depends on available memory either allocated by pga_aggregate_target (if using workarea_size_policy = auto) or hash_area_size (if using workarea_size_policy = manual). Block is the unit to measure hash join work in v$session_longops.
Even 20 block hash join may show up in v$session_longops
It seems that the main criterion to show up hash join in v$session_longops is the time to perform it i.e. is it longer than 6 seconds. That’s because one can see even hash join of 20 blocks as a long running operation. The test case of course is artificially slowed down to make hash join very slow. And it is as follows (full listing in 20HashJoinLongops.txt):
1) Table ParodyOfBig is created from dba_source with just 1300 rows.
2) workarea_size_policy is set to manual and hash_area_size to 50000.
3) Anonymous pl/sql block is created. It contains cursor with select joining ParodyOfBig to itself. To force hash join appropriate hint is used.
4) To slow down hash join after fetching each row we just wait for 0.03 seconds.
5) Anonymous block is executed and it takes 39.05 seconds to run. It matches up with calculated necessary time for executing this script i.e. 1300 rows * 0.03 seconds = 39 seconds.
6) One can see a row in v$session_longops that indicates that there were 20 blocks for hash join and the work took 15 seconds. I cannot explain why only 15 seconds are shown in elapsed_seconds column in v$session_longops.
So if you see a badly performing hash join with small number of blocks (small can be even in thousands) make sure that hash join actually isn’t doing something else behind the scenes. It probably won’t be dbms_lock.sleep as in this particular case, but possibilities to slow down execution flow between two cursor fetches are infinite.
Hash joins can either fly or crawl
Hash joins are very much affected by available memory and number of blocks to join is also dependant on available memory. In following example a table of 50000 rows was created from dba_source and joined to itself (full listing in HashJoinsFlyOrCrawl.txt). The same query was executed with different hash_area_size and as you can see it very much can affect both physical reads and execution time (which mostly is affected by reads and writes to temporary tablespace because hash area is too small). Depending on hash area size execution time can be as small as 0.01 second or as big as 8 and a half minutes.
Following table is a summary of test queries.
Hash area size
|
Query execution time
|
Hash blocks
|
Physical reads according to autotrace
|
16000000
|
0 00.01
|
?
|
0
|
8000000
|
0 00.03
|
?
|
936
|
4000000
|
0 01.03
|
?
|
1472
|
1000000
|
0 04.00
|
?
|
1718
|
500000
|
0 04.01
|
?
|
1786
|
300000
|
0 03.04
|
?
|
2722
|
150000
|
0 16.05
|
9288
|
9288
|
120000
|
0 19.05
|
13376
|
13376
|
110000
|
0 16.03
|
15262
|
15262
|
100000
|
0 54.00 (second time)
|
33666
|
33666 (second time)
|
90000
|
1 05.06
|
40052
|
40052
|
80000
|
1 22.02
|
49732
|
49732
|
70000
|
1 33.05
|
65798
|
65798
|
60000
|
8 38.05
|
388112
|
388112
|
50000
|
5 56.00
|
388112
|
388112
|
Table 1 Query execution time depending on hash area size
Of course if one uses workarea_size_policy = auto then hash_area_size doesn’t matter, instead pga_aggregate_target is used and a portion of it is allocated to hash join.
Linear prediction may be wrong
As already said Oracle considers long running operation to be linear. To show how Oracle mistakenly predicts remaining time I’ve created following test case (full listing in LinearPredictionMain.txt andLinearPredictionSecondSession.txt).
1) Table BIG with 50K rows is created.
2) Anonymous pl/sql block is created. It contains cursor with select joining BIG to itself. To force hash join appropriate hint is used.
3) To slow down hash join a small hash_area_size is allocated
4) Cursor just fetches row by row from the 1st till 50k except for rows between 15K and 18K where it just waits 0.03 seconds.
5) In another session a script just inserts last row from v$session_longops into a table to register the trend of events.
5) Following chart created from the trend of events table shows the situation. Starting from second 3 since the hash join appears in v$session_longops remaining time increases rather fast while work done (number of blocks/100) increases very slowly. Then in the 94th second remaining time reaches its spike and is 178 seconds although as we’ll later see all the work would complete in just 126 seconds. Starting from the 94th second remaining time goes down very fast and work done as fast goes up.
So there was a moment in time when hash join was already 94 seconds in v$session_longops and oracle predicted it to run 178 seconds more however it completed just in 24 seconds. On the other hand at the very start Oracle predicted that hash join would be over after 24 seconds although it actually needed 115 seconds to complete. Of course this is just an artificially created test case but many times the real world is quite the same because of various amount work to do in different phases of long operation (for example doing some calculations only for some values), different server workload at execution time, different net workload accepting results and many other factors that might influence the performance of particular long operation.
Table 2 Linear prediction of long running operation
Summary
There are several facts one has to remember about long running operations:
1) Not all operations that are running longer than 6 seconds are considered as long operations. Built-in long operation types are strongly defined although increasing with every new Oracle version.
2) There are some other criteria to show the particular operation type in v$session_longops.
3) Long operations of particular kind can be very different i.e. they can actually do many more things behind the scenes and one cannot find out that just looking at long operation.
4) Oracle considers long operations as linear operations (each unit of work takes the same amount of time) therefore estimated completion time can be inaccurate in case the real process is not linear.
References and Further reading
[1] Expert Oracle, Signature Edition By Thomas Kyte ISBN: 1-59059-525-4, Appendix A, DBMS_APPLICATION_INFO;
[2] Thread in Ask Tom, V$SESSION_LONGOPS, http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:1099233454171;
[3] Oracle® Database Reference, 10g Release 2 (10.2), V$SESSION_LONGOPS, http://download-uk.oracle.com/docs/cd/B19306_01/server.102/b14237/dynviews_2092.htm;
[4] What is the difference between an 'index full scan' and an 'index fast full scan', by Jonathan Lewis, http://www.jlcomp.demon.co.uk/faq/index_scans.html;
[5] Oracle® Database Performance Tuning Guide, 10g Release 2 (10.2), 13 The Query Optimizer, 13.5.3.7 Fast Full Index Scans, http://download-uk.oracle.com/docs/cd/B19306_01/server.102/b14211/optimops.htm#i52044;
[6] Thread in Ask Tom, Hash Join, http://asktom.oracle.com/pls/asktom/f?p=100:11:0::::P11_QUESTION_ID:65506569258230;
[7] SQL Memory Management in Oracle9i, by Benoît Dageville, Mohamed Zait, http://www.cs.ust.hk/vldb2002/VLDB2002-proceedings/papers/S29P03.pdf. Includes information how Hash Joins are implemented in Oracle.
[8] Working with Automatic PGA, by Christo Kutrovsky, http://www.pythian.com/documents/Working_with_Automatic_PGA.ppt. Presentation about automatic PGA including info about Hash Joins.
[9] If only more developers used the DBMS_APPLICATION_INFO package , by Andy Campbell, http://oracleandy.blogspot.com/2006/09/if-only.html. Article about DBMS_APPLICATION_INFO.SET_SESSION_LONGOPS procedure that allows user to set his own types of long running operations.
