As part of the research I did for the 2nd edition of our Exadata book I used session statistics quite heavily. Session statistics can provide additional insights in situations where the wait interface on its own doesn't get you any further.
On the command line, my tools of choice are either Tanel Poder's excellent Session Snapper or Adrian Billington's mystats utility. There are of course others, it just so happened that I've been using the previous two quite heavily. If you prefer a graphical front-end such as SQL Developer, you can grab the change in session statistics easily as described in an earlier post.
I'm not sure why it never occurred to me to check if SQL Developer's best friend, sqlcl, has the same functionality. Well it does, and that's great news. The other great news is that you can download sqlcl directly from Oracle's website now.
Downloading SQLcl the new way
The first step to complete is to pull the latest version of sqlcl. Many thanks to Connor McDonald who told me there is a super-easy way to always get the latest version. Just use the following URL:
https://download.oracle.com/otn_software/java/sqldeveloper/sqlcl-latest.zip
Great! I don't even need to worry about the version:
$ wget https://download.oracle.com/otn_software/java/sqldeveloper/sqlcl-latest.zip --2021-06-10 14:37:29-- https://download.oracle.com/otn_software/java/sqldeveloper/sqlcl-latest.zip Resolving download.oracle.com (download.oracle.com)... 104.76.200.85 Connecting to download.oracle.com (download.oracle.com)|104.76.200.85|:443... connected. HTTP request sent, awaiting response... 200 OK Length: 36960602 (35M) [application/zip] Saving to: 'sqlcl-latest.zip' sqlcl-latest.zip 100%[====================================>] 35.25M 6.35MB/s in 5.7s 2021-06-10 14:37:35 (6.19 MB/s) - 'sqlcl-latest.zip' saved [36960602/36960602]
Note that I'm downloading sqlcl-latest.zip, which translates to 21.1.1.113.1704 at the time of writing:
$ cd sqlcl/bin && ./sql -V SQLcl: Release 21.1.1.0 Production Build: 21.1.1.113.1704
With the latest sqlcl release unzipped it's time to grab some session statistics.
Session Statistics, please!
To keep matters reasonably simple I'm using a non-partitioned table for my demonstration. As always, my examples use the excellent Swingbench (Order Entry) benchmark schema. Once connected to the database, I can start investigating. By the way I'm running this query on Oracle 19c in a VM on my laptop.
The first step is to enable auto-trace as shown here:
SQL> show version Oracle SQLDeveloper Command-Line (SQLcl) version: 21.1.1.0 build: 21.1.1.113.1704 SQL> help set autotrace SET AUTOTRACE SET AUTOT[RACE] {OFF|ON|TRACE[ONLY]} SQL> set autotrace on Autotrace Enabled Shows the execution plan as well as statistics of the statement. Let's run a query against the orders table:
SQL> select count(*) from soe.orders; COUNT(*) ___________ 17157480 Explain Plan ----------------------------------------------------------- Plan hash value: 508073128 ---------------------------------------------------------------------- | Id | Operation | Name | Rows | Cost (%CPU)| Time | ---------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 62161 (1)| 00:00:03 | | 1 | SORT AGGREGATE | | 1 | | | | 2 | TABLE ACCESS FULL| ORDERS | 17M| 62161 (1)| 00:00:03 | ---------------------------------------------------------------------- Statistics ----------------------------------------------------------- 103 CPU used by this session 104 CPU used when call started 209348 Cached Commit SCN referenced 4 Commit SCN cached 510 DB time 4171496 Effective IO time 3587 Number of read IOs issued 42 Requests to/from client 42 SQL*Net roundtrips to/from client 2 buffer is not pinned count 587 bytes received via SQL*Net from client 79087 bytes sent via SQL*Net to client 3 calls to get snapshot scn: kcmgss 8 calls to kcmgcs 1870921728 cell physical IO interconnect bytes 4 cleanout - number of ktugct calls 4 cleanouts only - consistent read gets 4 commit txn count during cleanout 228394 consistent gets 228384 consistent gets direct 4 consistent gets examination 4 consistent gets examination (fastpath) 10 consistent gets from cache 6 consistent gets pin 6 consistent gets pin (fastpath) 1 cursor authentications 2 enqueue releases 2 enqueue requests 2 execute count 6884470 file io wait time 4 immediate (CR) block cleanout applications 81920 logical read bytes from cache 228380 no work - consistent read gets 7233 non-idle wait count 418 non-idle wait time 2 opened cursors cumulative 1 opened cursors current 1 parse count (hard) 2 parse count (total) 1 parse time elapsed 3587 physical read IO requests 1870921728 physical read bytes 3587 physical read total IO requests 1870921728 physical read total bytes 3578 physical read total multi block requests 228384 physical reads 228384 physical reads direct 6 process last non-idle time 1 recursive calls 228394 session logical reads 1 sorts (memory) 2010 sorts (rows) 228384 table scan blocks gotten 17157480 table scan disk non-IMC rows gotten 17157480 table scan rows gotten 1 table scans (direct read) 1 table scans (long tables) 418 user I/O wait time 43 user calls SQL>
This is pretty nifty in my opinion. There's an execution plan and a whole raft of relevant session statistics. It would be even better if sqlcl displayed a-rows and e-rows, but you can use Tanel's tpt-oracle scripts for that ;)
Happy Troubleshooting!
