Re: Increased runtime and 4 xids for one insert

  • From: Tanel Poder <tanel@xxxxxxxxxxxxxx>
  • To: contact@xxxxxxxx
  • Date: Thu, 11 Apr 2024 14:01:46 -0400

If you have ASH, you have SQL Monitoring too and if this thing took hours,
Oracle may already have saved a previous SQL Mon report to data dictionary.

   -
   https://mauro-pagano.com/2015/05/04/historical-sql-monitor-reports-in-12c/


If you find a single saved report from that time, check if the "Executions"
column of the 2nd line from the top (should be LOAD DATA CONVENTIONAL)
shows 4 or just 1 (and double check that it's a serial insert-select.

If it's 4, it's a DML restart that happens under the hood.

If you see (up to) 4 different SQLMon reports all with a different
SQL_EXEC_START + SQL_EXEC_ID values (and Executions is 1), then it's your
app that restarts the query.

In the latter case, it could be any error (that doesn't get logged to
alert.log) like perhaps running out of UNDO or TEMP tablespace space or any
other error (I don't remember if such errors are logged into alert, like
the ORA-1555 errors).

You could use Snapper too if the operation is running (as Jonathan said,
it's best for troubleshooting activity over shorter intervals), but you can
run it every 15 mins or so to see if your session is busy making progress
(and what is it spending its time on) or is it rolling back ("undo records
applied" metric):

   - @snapper all 10 1 SID

(you need to replace the SID with your actual session ID of interest).

You could also use my @trans.sql to monitor ongoing transactions from
v$transaction and see if the transaction STATE changes from "ACTIVE" to
"ACTIVE ROLLING BACK" (and the used_ublk starts to drop):

   - https://github.com/tanelpoder/tpt-oracle/blob/master/trans.sql

If nothing makes sense, then you can always enable SQL trace (without wait
events) and see what happens under the hood. This is less likely, but it's
possible that some recursive operation executed by Oracle under the hood
fails and the whole insert gets rolled back. I recall a bug/dictionary data
issue from the past, where gathering optimizer stats on a new partition hit
a primary key violation in some data dictionary table (and you hit these
corner cases more likely the more fancy new features you have enabled, like
live statistics gathering for example...)

Tanel.
tanelpoder.com

Other related posts: