Just added Oracle Monitor for Graylog in https://marketplace.graylog.org/
Let me know !
Thanks
Enjoy!!
Let me know !
Thanks
Enjoy!!
6f429244e498457b8400e72e4af683b0
parole....soltanto parole....
[oracle@localhost ~]$ sqlplus pmuser/oracle@PDB1
SQL*Plus: Release 12.1.0.1.0 Production on Tue Apr 22 10:28:55 2014
Copyright (c) 1982, 2013, Oracle. All rights reserved.
Last Successful login time: Tue Apr 22 2014 10:17:34 +02:00
Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
PDB1@ORCL> alter session set statistics_level= ALL;
Session altered.
PDB1@ORCL> set linesize 100;
PDB1@ORCL> SET AUTOTRACE ON
select owner,object_name,object_id from t2
order by owner,object_name fetch first 5 rows only;PDB1@ORCL> 2
OWNER
----------------------------------------------------------------------------------------------------
OBJECT_NAME
----------------------------------------------------------------------------------------------------
OBJECT_ID
----------
APEX_040200
APEX
93296
APEX_040200
APEX$ARCHIVE_CONTENTS
94132
OWNER
----------------------------------------------------------------------------------------------------
OBJECT_NAME
----------------------------------------------------------------------------------------------------
OBJECT_ID
----------
APEX_040200
APEX$ARCHIVE_CONTENTS_IDX1
94136
APEX_040200
APEX$ARCHIVE_HEADER
OWNER
----------------------------------------------------------------------------------------------------
OBJECT_NAME
----------------------------------------------------------------------------------------------------
OBJECT_ID
----------
94130
APEX_040200
APEX$ARCHIVE_HISTORY
94137
Execution Plan
----------------------------------------------------------
Plan hash value: 3975347511
-----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 89325 | 24M| | 1265 (1)| 00:00:01 |
|* 1 | VIEW | | 89325 | 24M| | 1265 (1)| 00:00:01 |
|* 2 | WINDOW SORT PUSHED RANK| | 89325 | 3140K| 4216K| 1265 (1)| 00:00:01 |
| 3 | TABLE ACCESS FULL | T2 | 89325 | 3140K| | 418 (1)| 00:00:01 |
-----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("from$_subquery$_002"."rowlimit_$$_rownumber"<=5)
2 - filter(ROW_NUMBER() OVER ( ORDER BY "OWNER","OBJECT_NAME")<=5)
Statistics
----------------------------------------------------------
80 recursive calls
0 db block gets
1596 consistent gets
1512 physical reads
0 redo size
890 bytes sent via SQL*Net to client
543 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
12 sorts (memory)
0 sorts (disk)
5 rows processed
PDB1@ORCL>
In this case we have no db time in Statistics, while in SqlDeveloper there are.
[oracle@localhost ~]$ sqlplus pmuser/oracle@PDB1
SQL*Plus: Release 12.1.0.1.0 Production on Tue Apr 22 11:40:11 2014
Copyright (c) 1982, 2013, Oracle. All rights reserved.
Last Successful login time: Tue Apr 22 2014 10:29:23 +02:00
Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.1.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options
PDB1@ORCL> set linesize 100
PDB1@ORCL> set heading off
PDB1@ORCL> select sys_context('USERENV','SID') from dual;
45
PDB1@ORCL> SET AUTOTRACE ON
select owner,object_name,object_id from t2
order by owner,object_name fetch first 5 rows only;
PDB1@ORCL> 2
APEX_040200
APEX
93296
APEX_040200
APEX$ARCHIVE_CONTENTS
94132
APEX_040200
APEX$ARCHIVE_CONTENTS_IDX1
94136
APEX_040200
APEX$ARCHIVE_HEADER
94130
APEX_040200
APEX$ARCHIVE_HISTORY
94137
Execution Plan
----------------------------------------------------------
Plan hash value: 3975347511
-----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 89325 | 24M| | 1265 (1)| 00:00:01 |
|* 1 | VIEW | | 89325 | 24M| | 1265 (1)| 00:00:01 |
|* 2 | WINDOW SORT PUSHED RANK| | 89325 | 3140K| 4216K| 1265 (1)| 00:00:01 |
| 3 | TABLE ACCESS FULL | T2 | 89325 | 3140K| | 418 (1)| 00:00:01 |
-----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("from$_subquery$_002"."rowlimit_$$_rownumber"<=5)
2 - filter(ROW_NUMBER() OVER ( ORDER BY "OWNER","OBJECT_NAME")<=5)
Statistics
----------------------------------------------------------
79 recursive calls
0 db block gets
1597 consistent gets
1516 physical reads
0 redo size
890 bytes sent via SQL*Net to client
543 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
7 sorts (memory)
0 sorts (disk)
5 rows processed
PDB1@ORCL> set autotrace off
PDB1@ORCL> select name, value from v$statname a, v$mystat b
where
b.value <> 0
and b.statistic# = a.statistic#
and b.SID = 45;
Requests to/from client 31
logons cumulative 1
logons current 1
opened cursors cumulative 919
opened cursors current 11
user calls 51
recursive calls 5978
recursive cpu usage 27
pinned cursors current 11
session logical reads 8394
CPU used when call started 29
CPU used by this session 30
DB time 249
user I/O wait time 136
non-idle wait time 136
non-idle wait count 731
session connect time 1398159611
process last non-idle time 1398159611
session uga memory 2933728
session uga memory max 2933728
messages sent 2
session pga memory 10064008
session pga memory max 10260616
enqueue requests 89
enqueue releases 84
physical read total IO requests 695
physical read total bytes 16588800
cell physical IO interconnect bytes 16588800
db block gets 36
db block gets from cache 36
db block gets from cache (fastpath) 2
consistent gets 8358
consistent gets from cache 6856
consistent gets pin 3327
consistent gets pin (fastpath) 2915
consistent gets examination 3529
consistent gets examination (fastpath) 3438
consistent gets direct 1502
logical read bytes from cache 56459264
physical reads 2025
physical reads cache 523
physical reads direct 1502
physical read IO requests 695
physical read bytes 16588800
db block changes 37
consistent changes 20
free buffer requested 531
dirty buffers inspected 12
pinned buffers inspected 1
hot buffers moved to head of LRU 2957
free buffer inspected 638
commit cleanouts 2
commit cleanouts successfully completed 2
switch current to new buffer 2
physical reads cache prefetch 20
shared hash latch upgrades - no wait 84
calls to kcmgcs 155
calls to kcmgas 6
calls to get snapshot scn: kcmgss 1817
redo entries 12
redo size 5420
redo synch time (usec) 1
redo synch time overhead (usec) 146
redo synch time overhead count ( 2ms) 1
redo synch writes 2
redo write info find 1
file io wait time 1178238
Number of read IOs issued 192
temp space allocated (bytes) 3145728
undo change vector size 3712
no work - consistent read gets 4677
deferred (CURRENT) block cleanout applications 1
IMU Flushes 1
IMU ktichg flush 1
CLI Thru Wrt 1
table scans (short tables) 42
table scans (long tables) 1
table scans (direct read) 1
table scan rows gotten 102715
table scan blocks gotten 1603
table fetch by rowid 2311
table fetch continued row 37
cluster key scans 187
cluster key scan block gets 190
rows fetched via callback 724
lob writes 1
lob writes unaligned 1
index fetch by key 962
index scans kdiixs1 852
HSC Heap Segment Block Changes 10
sql area evicted 29
CCursor + sql area evicted 18
session cursor cache hits 850
session cursor cache count 49
cursor authentications 31
buffer is pinned count 723
buffer is not pinned count 5962
workarea memory allocated 658
workarea executions - optimal 133
parse time cpu 10
parse time elapsed 66
parse count (total) 487
parse count (hard) 71
execute count 1086
bytes sent via SQL*Net to client 12451
bytes received via SQL*Net from client 8880
SQL*Net roundtrips to/from client 31
sorts (memory) 283
sorts (rows) 91107
109 rows selected.
PDB1@ORCL>
In this case we have all statistics DB TIME also.
We need to ask to Jeff Smith more explanation about...
Your comments are welcome, as usual....
HTH
create table t2 as select * from all_objects;
create index idx_t2 on t2(owner,object_name);
SET AUTOTRACE ON
select owner,object_name,object_id from t2
order by owner,object_name fetch first 5 rows only;
Autotrace Enabled
Shows the execution plan as well as statistics of the statement.
OWNER OBJECT_NAME OBJECT_ID
APEX_040200 APEX 88901
APEX_040200 APEX$ARCHIVE_CONTENTS 89728
APEX_040200 APEX$ARCHIVE_CONTENTS_IDX1 89732
APEX_040200 APEX$ARCHIVE_HEADER 89726
APEX_040200 APEX$ARCHIVE_HISTORY 89733
Plan hash value: 3975347511
-----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 86477 | 23M| | 3191 (1)| 00:00:01 |
|* 1 | VIEW | | 86477 | 23M| | 3191 (1)| 00:00:01 |
|* 2 | WINDOW SORT PUSHED RANK| | 86477 | 11M| 13M| 3191 (1)| 00:00:01 |
| 3 | TABLE ACCESS FULL | T2 | 86477 | 11M| | 412 (1)| 00:00:01 |
-----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("from$_subquery$_002"."rowlimit_$$_rownumber"<=5)
2 - filter(ROW_NUMBER() OVER ( ORDER BY "OWNER","OBJECT_NAME")<=5)
Note
-----
- dynamic statistics used: dynamic sampling (level=2)
Statistics
-----------------------------------------------------------
2 CCursor + sql area evicted
83 CPU used by this session
83 CPU used when call started
87 DB time
25 Number of read IOs issued
88 Requests to/from client
88 SQL*Net roundtrips to/from client
63 buffer is not pinned count
1104 bytes received via SQL*Net from client
35629 bytes sent via SQL*Net to client
8 calls to get snapshot scn: kcmgss
13 calls to kcmgcs
15081472 cell physical IO interconnect bytes
1585 consistent gets
1510 consistent gets direct
2 consistent gets examination
2 consistent gets examination (fastpath)
75 consistent gets from cache
73 consistent gets pin
22 consistent gets pin (fastpath)
2 enqueue releases
2 enqueue requests
6 execute count
1074 file io wait time
331 free buffer requested
2 index scans kdiixs1
614400 logical read bytes from cache
1573 no work - consistent read gets
164 non-idle wait count
1 non-idle wait time
6 opened cursors cumulative
2 opened cursors current
2 parse count (hard)
4 parse count (total)
1 parse time cpu
2 parse time elapsed
76 physical read IO requests
15081472 physical read bytes
76 physical read total IO requests
15081472 physical read total bytes
25 physical read total multi block requests
1841 physical reads
331 physical reads cache
280 physical reads cache prefetch
1510 physical reads direct
7 recursive calls
1 recursive cpu usage
-1 session cursor cache count
3 session cursor cache hits
1585 session logical reads
51 shared hash latch upgrades - no wait
3 sorts (memory)
90762 sorts (rows)
1571 table scan blocks gotten
93514 table scan rows gotten
1 table scans (direct read)
2 table scans (short tables)
89 user calls
5 workarea executions - optimal
Ci siamo chiesti come mai nell'esempio proposto venisse utilizzato l'indice appositamente creato mentre nel nostro no.
Nemmeno aggiornando le statistiche la situazione non cambiava.
Sono andato a verificare in v$parameter il parametro dell'optimizer e l'ho trovato ALL_ROWS la cosa mi ha subito
insospettito quindi ho provato con
alter session set OPTIMIZER_MODE = FIRST_ROWS
SET AUTOTRACE ON
select owner,object_name,object_id from t2
order by owner,object_name fetch first 5 rows only;
Autotrace Enabled
Shows the execution plan as well as statistics of the statement.
OWNER OBJECT_NAME OBJECT_ID
APEX_040200 APEX 88901
APEX_040200 APEX$ARCHIVE_CONTENTS 89728
APEX_040200 APEX$ARCHIVE_CONTENTS_IDX1 89732
APEX_040200 APEX$ARCHIVE_HEADER 89726
APEX_040200 APEX$ARCHIVE_HISTORY 89733
Plan hash value: 2588503356
----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 89906 | 24M| 69551 (1)| 00:00:03 |
|* 1 | VIEW | | 89906 | 24M| 69551 (1)| 00:00:03 |
|* 2 | WINDOW NOSORT STOPKEY | | 89906 | 3160K| 69551 (1)| 00:00:03 |
| 3 | TABLE ACCESS BY INDEX ROWID| T2 | 89906 | 3160K| 69551 (1)| 00:00:03 |
| 4 | INDEX FULL SCAN | IDX_T2 | 89906 | | 524 (1)| 00:00:01 |
----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("from$_subquery$_002"."rowlimit_$$_rownumber"<=5)
2 - filter(ROW_NUMBER() OVER ( ORDER BY "OWNER","OBJECT_NAME")<=5)
Statistics
-----------------------------------------------------------
19 Requests to/from client
19 SQL*Net roundtrips to/from client
4 buffer is not pinned count
9 buffer is pinned count
463 bytes received via SQL*Net from client
32492 bytes sent via SQL*Net to client
2 calls to get snapshot scn: kcmgss
2 calls to kcmgcs
5 consistent gets
2 consistent gets examination
2 consistent gets examination (fastpath)
5 consistent gets from cache
3 consistent gets pin
3 consistent gets pin (fastpath)
1 cursor authentications
2 execute count
1 index scans kdiixs1
40960 logical read bytes from cache
3 no work - consistent read gets
19 non-idle wait count
2 opened cursors cumulative
1 opened cursors current
2 parse count (total)
5 session logical reads
1 sorts (memory)
855 sorts (rows)
6 table fetch by rowid
20 user calls
3 workarea executions - optimal
Adesso l'indice viene utilizzato correttamente e il piano di esecuzione è migliorato sensibilmente.
Presumo che nell'esempio proposto da Tom Kyte questo parametro fosse impostato con appunto FIRST_ROWS.