tahsin sarlak, November 17, 2015 - 7:52 am UTC
getting back to the original question, An AWR does not provide the information as to which specific SQL's cause which event. However ASH does
A reader, November 17, 2015 - 9:55 am UTC
Hi Connor,
Thanks for the reply.
I was looking for the statement because I would know what schema executes that statement since I am familiar with the application SQL. Based on your query on performance views, I gather that I may not be able to figure out what SQL listed in the AWR report caused all of the log file syncs, right? I am looking at an AWR report from last week so querying performance views won't help identify the cause from last week.
Our box is not CPU bound.
November 18, 2015 - 6:28 am UTC
The dba_hist... views will have session statistic information.
You could mine them for 'user commits', and then try this back to dba_hist_active_sess_history and see what you can glean from there.
Hope this helps.
continuation ...
John Cantu, November 17, 2015 - 4:06 pm UTC
I did find an extremely large amount of "user commits" in the AWR report.
user commits 29,737
Is there anyway that I can find out from this old AWR report, what process executed all of these "user commits"? When a background process commits, does it also increment "user commits"? It is very odd
BTW: I do know that the ASH report would tell me what user & SQL was the cause of the 'log file sync' in the "Top SQL with Top Events" section. Unfortunately, the details in there are dropped off if we gather the report too late. My assumption is that the details are only available for an hour after they are written to the dynamic performance view (V$ views). Once they are transferred to the static data dictionary (DBA_*), a lot of the details are truncated.
Thanks for your help.
John
November 18, 2015 - 6:38 am UTC
Does DBA_HIST_ACTIVE_SESS_HISTORY assist ?
A reader, November 18, 2015 - 6:26 am UTC
select * from dba_hist_active_sess_history where event='log file sync'
DBA_HIST_ACTIVE_SESS_HISTORY does help
John Cantu, November 18, 2015 - 10:38 pm UTC
Hi Connor,
DBA_HIST_ACTIVE_SESS_HISTORY did allow me to figure out what sessions were waiting on "log file sync", but unfortunately it didn't include the SQL_ID.
BTW: These "DBA_HIST_*_HISTORY" views are great. I wish that someone would provide a book that would help us extract information. About 15 years ago I owned a book that showed us how to extract our own data from the statspack tables. Do you know of any?
Finally, I figured out what confused me when I looked at the AWR report. In the AWR report I saw:
Tota Wait % DB
Event Waits Time Avg(ms) time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
log file sync 30,256 3801 126 98.3 Commit
3800 seconds spent on "log file sync". Then, I went to "SQL ordered by Elapsed Time" to make a connection with the log file sync wait time. However, in there I saw that the most costly SQL statement only took 8 seconds! that is what had me confused since "log file sync" took over 3800sec.
Next, I looked at "SQL ordered by Gets" section. Here I find all of the Insert and delete statements that must execute a "commit" after each insert and delete.
Buffer Gets Elapsed
Gets Executions per Exec %Total Time (s)
----------- ----------- ------------ ------ ----------
48,132 5,768 8.3 5.2 0.8
INSERT INTO "........."
42,118 5,767 7.3 4.6 0.8
DELETE FROM "........"
etc.
3800 seconds were spent on "log file sync" yet, if add up all of the SQL executed against the database, it doesn't equal more than 500 seconds. What is going on here? 3800 seconds were spent on "log file sync". I would expect insert & delete statements to be > 3800 since I am sure that they were slowed down by "log file sync" time, right?
Thanks
November 18, 2015 - 11:17 pm UTC
If 500 people, all commit at once, and wait for 1second on log file sync, then only 1 second has passed, but we have captured 500 seconds of "log file sync".
So it can easily exceed the true elapsed wall clock time.
Hope this helps.
shocked
John Cantu, November 19, 2015 - 12:24 am UTC
Hi Connor,
I think I understand. So Oracle will add the wait times like 'db file sequential' and 'buffer busy waits', but it will not add wait events like 'log file sync'. I then have to think about whether the wait events happen outside of the SQL call or within the SQL call so that I can get an idea of the clock time. It would be good if Oracle categorized the wait events as wait events that happen within SQL and outside of SQL.
Which SQL waits for the log file sync ?
Hemant K Chitale, January 14, 2016 - 5:53 am UTC