things changes ...
Sokrates, May 20, 2010 - 9:25 am UTC
They are rare in a queryseems to me that nowadays there is a case when they are very often: they seem to occur quite numerously when using recursive subquery factoring.
For example (it's just an example, the same effect also occurs when querying "real" tables)
select level n from dual connect by level <= 10000;
10000 rows selected.
Elapsed: 00:00:00.50
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
0 consistent gets
0 physical reads
0 redo size
...
butwith n(n) as (select 1 from dual union all select n+1 from n where n<=9999) select * from n;
10000 rows selected.
Elapsed: 00:00:00.56
Statistics
----------------------------------------------------------
1 recursive calls
7332 db block gets
0 consistent gets
0 physical reads
0 redo size
Could you shed some light on the underlyings ?
May 24, 2010 - 12:06 pm UTC
interesting, I do not know the root cause, if I stumble upon it - i'll try to update. Not sure what block it is getting - even does it with a pipelined function to generate a row (no tables queried at all)
interesting ...
Sokrates, May 26, 2010 - 2:24 am UTC
sokrates > set arraysize 5000 autotr traceonly timi on
sokrates > variable n number
sokrates > exec :n:=3e8
PL/SQL procedure successfully completed.
Elapsed: 00:00:00.00
sokrates > with n(n) as (select 1 from dual union all select n+1 from n where n<=:n) select * from n;
300000001 rows selected.
Elapsed: 05:16:51.60
Execution Plan
----------------------------------------------------------
Plan hash value: 1492144221
--------------------------------------------------------------------------------
------------------
| Id | Operation | Name | Rows | Bytes | Cost
(%CPU)| Time |
--------------------------------------------------------------------------------
------------------
| 0 | SELECT STATEMENT | | 2 | 26 | 4
(0)| 00:01:44 |
| 1 | VIEW | | 2 | 26 | 4
(0)| 00:01:44 |
| 2 | UNION ALL (RECURSIVE WITH) BREADTH FIRST| | | |
| |
| 3 | FAST DUAL | | 1 | | 2
(0)| 00:00:52 |
|* 4 | RECURSIVE WITH PUMP | | | |
| |
--------------------------------------------------------------------------------
------------------
Predicate Information (identified by operation id):
---------------------------------------------------
4 - filter("N"<=TO_NUMBER(:N))
Statistics
----------------------------------------------------------
23451 recursive calls
4139408900 db block gets
0 consistent gets
3045588 physical reads
0 redo size
2307140120 bytes sent via SQL*Net to client
660524 bytes received via SQL*Net from client
60002 SQL*Net roundtrips to/from client
300000002 sorts (memory)
0 sorts (disk)
300000001 rows processed
sokrates > set autotr off lines 300 pages 5000
sokrates > select * from (
select rank() over (order by e.value desc) rank, e.value, n.name
from v$mystat e, v$statname n
where n.statistic#=e.statistic#
)
where rank <= 44
order by rank desc
/
2 3 4 5 6 7 8
RANK VALUE NAME
---------- ---------- --------------------------------------------------
44 60055 SQL*Net roundtrips to/from client
43 60084 user calls
42 677050 bytes received via SQL*Net from client
41 818876 user I/O wait time
40 820084 non-idle wait time
36 883421 physical writes
36 883421 physical writes non checkpoint
36 883421 physical writes direct
36 883421 physical writes direct temporary tablespace
34 1033244 CPU used when call started
34 1033244 CPU used by this session
33 1632084 dirty buffers inspected
32 1857685 DB time
31 2580624 session uga memory
27 3045590 physical read IO requests
27 3045590 physical reads cache
27 3045590 physical reads
27 3045590 physical read total IO requests
26 3176996 file io service time
25 3346374 non-idle wait count
24 4194304 temp space allocated (bytes)
23 4844443 free buffer inspected
22 5164732 free buffer requested
21 5667806 hot buffers moved to head of LRU
20 8986968 session pga memory
19 105718088 session uga memory max
18 106504536 session pga memory max
17 300000027 sorts (memory)
16 300000032 workarea executions - optimal
15 300002655 sorts (rows)
14 613230805 consistent changes
13 613230835 db block changes
11 1274797172 process last non-idle time
11 1274797172 session connect time
10 2307165260 bytes sent via SQL*Net to client
8 4139408967 db block gets
8 4139408967 db block gets from cache
7 4139409107 session logical reads
5 7236984832 physical write bytes
5 7236984832 physical write total bytes
4 8099390291 file io wait time
2 2.4949E+10 physical read total bytes
2 2.4949E+10 physical read bytes
1 3.2186E+10 cell physical IO interconnect bytes
44 rows selected.
what is "cell physical IO interconnect bytes" ? can't find it in the docu.
v$tempseg_usage showed three temp segments for the session:
2 of segtype LOB_INDEX and one of segtype SORT
v$temporary_lobs didn't show anything
sokrates > select level n from dual connect by level <= :n;
ERROR:
ORA-30009: Not enough memory for CONNECT BY operation
6995000 rows selected.
would be very interesting to know what's happening behind the scene ...
May 26, 2010 - 7:58 am UTC
I think that cell physical IO is a red herring, it is exadata related... It does increase, but I don't see the connection.
difference between "file io service time' and file io wait time'
sreeni, November 19, 2012 - 11:05 pm UTC
Hi Tom,
Can you give me the difference between 'file io service time' and 'file io wait time'. When i compare the two time periods between slow performance of system and high performance of the system , i could see below metrics.
During good performance
file io service time - 1,930.28 per transaction.
file io wait time - 48,869,220.40 per transsactin.
During bad performance.
file io service time - 6,181.99 per transaction.
file io wait time - 1,556,365,563.24 per transsactin.
Regards,Sreeni.