You probably are already familiar with my ash_wait_chains scripts that use CONNECT BY for walking through the blocking_session fields in ASH and report “wait chains”, signatures of complex waits involving other database sessions.
Since ASH is “just” a history of V$SESSION, it’s sensible to assume that one could sample the current wait chains just by querying the GV$SESSION views, instead of summarizing history from ASH. And indeed it’s possible - here’s my Session-Wait-Chains script swc.sql
that queries only GV$SESSION, thus doesn’t need licenses for using ASH.
As usual, pull the latest changes from my TPT repository.
SQL> @help swc.sql
NAME DESCRIPTION USAGE
----------- ------------------------------------------------------------ ------------------------------
swc.sql Display current wait chains (multi-session wait signature, a @swc <grouping_cols> <filters>
session waiting for another session etc.) from GV$SESSION @swc program2||event2 1=1
Here’s an example of a busy OLTP benchmark workload during the exact moment of a redo log switch:
SQL> @swc program2||event2 1=1 -- Display Session Wait Chain Signatures script v0.1 BETA by Tanel Poder ( https://tanelpoder.com ) SESSIONS WAIT_CHAIN ---------- ----------------------------------------------------------------------------------------------- 27 -> (JDBC Thin Client) db file sequential read 15 -> (JDBC Thin Client) log file sync -> (LGWR) control file sequential read 15 -> (JDBC Thin Client) log file sync 11 -> (DBWn) db file async I/O submit 5 -> (JDBC Thin Client) db file parallel read 1 -> (sqlplus) switch logfile command 1 -> (SMON) enq: CR - block range reuse ckpt [mode=6] -> (CKPT) rdbms ipc message 1 -> (LGWR) control file sequential read 1 -> (sqlplus) switch logfile command -> (LGWR) control file sequential read 1 -> (SMON) enq: CR - block range reuse ckpt [mode=6]
As V$ views do not have read consistency and changes in V$SESSION state can happen fast, you might see some glitches in the data. For example, some committing sessions waiting for log file sync wait event (waiting for LGWR ACK) while not pointing to LGWR as the blocking session (there’s no arrow pointing to LGWR in line #3 in the above output).
However the line #2 in the above output shows plenty of sessions waiting for log file sync, while LGWR itself was not writing into the redo log file, but reading something from a control file! This is what happens during the log switches, control file I/O latency is also important if you want low latency commits all the time.
As the swc.sql
script shows just one sample of GV$SESSION, you probably want to run it a few times to avoid getting misled by one outlier sample by accident. Of course, the ASH based scripts don’t have this problem, as they compute the wait chains from many ASH samples.
I’ll write a second part about “log file switch latency tuning” in the future (I’m trying to write shorter posts, but more frequently now).
That’s all, you can download the latest TPT scripts from GitHub or just as a .zip file.