Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Usenet -> c.d.o.server -> PL/SQL log sync waits, log file parallel write waits and redo writes
Hi,
After reading Steve Adams Web site i did a small experiment.
Can someone please better explain the results to me.
I wrote this in an file called dummy.sql
set serveroutput on
declare
t1 number;
t2 number;
begin
select hsecs into t1 from v$timer;
dbms_output.put_line(t1);
for i in 1..1000 loop
insert into x values(1);
commit;
end loop;
select hsecs into t2 from v$timer;
dbms_output.put_line(t2);
end;
/
I opened One SQL*PLUS session and create the table x.
CREATE TABLE X(A NUMBER);
I gave this SQL to find this sessions SID
select sid,serial#,username
from v$session
where audsid=(
select userenv('sessionid') from dual)
SID SERIAL# USERNAME
----- ------- ----------
8 873 SYS 1 row selected.
I know that the SID of LGWR process in my instance is 3.
I wrote this in a file called sess.sql
col name form a30
col value form 999999999999
select a.sid,b.name,a.value
from v$sesstat a,v$statname b
where a.statistic#=b.statistic#
and (b.name like 'redo%' or b.name like '%log%')
and a.value <>0
and sid in (&&1,3)
order by 3
/
col sid form 999
col event form a30
col total_waits head "Total|Waits"
select sid,event,total_waits
from v$session_event
where sid in (&&1,3)
and event like '%log%'
order by 1,2
/
I opened another SQL*PLUS session.
Now in the 2nd session i gave this
sys_at_DBA> @sess.sql
SID NAME VALUE ---- ------------------------------ ------------- 3 logons cumulative 1 8 logons cumulative 1 3 logons current 1 8 logons current 1 8 redo log space requests 3 8 redo buffer allocation retries 8 8 redo synch writes 13 3 redo writes 2763 8 redo entries 9335 3 redo blocks written 12314 8 session logical reads 52895 3 redo wastage 285844 8 redo size 2686012
13 rows selected.
Total SID EVENT Waits ---- ------------------------------ ---------- 3 log file parallel write 2763 3 log file sequential read 10 3 log file single write 16 8 log buffer space 5 8 log file switch completion 3 8 log file sync 13
6 rows selected.
Immediately after this i gave this in the 1st session
sys_at_DBA> @dummy.sql
596764178
596764220
PL/SQL procedure successfully completed.
Immediately after this completed in the 1st session, i gave this in the 2nd session
SID NAME VALUE ---- ------------------------------ ------------- 3 logons cumulative 1 8 logons cumulative 1 3 logons current 1 8 logons current 1 8 redo log space requests 3 8 redo buffer allocation retries 8 8 redo synch writes 14 3 redo writes 2846 8 redo entries 11340 3 redo blocks written 13520 8 session logical reads 56903 3 redo wastage 307968 8 redo size 3262044
13 rows selected.
Total SID EVENT Waits ---- ------------------------------ ---------- 3 log file parallel write 2846 3 log file sequential read 10 3 log file single write 16 8 log buffer space 5 8 log file switch completion 3 8 log file sync 14
6 rows selected.
5 rows selected.
Now I made the following observations
1) What Steve Adams Said about log file sync is right. Even though i
had committed 100 times in the loop, the logfile sync has incremented
by only 1.This means commits in PL/SQL dont wait for log sync until
the end of the PL/SQL call.
2) The number of redo blocks written was 1206 does this mean that 1 block was being used for each transaction ? Does this mean that for applications with short transactions, it is better to turn off log_checkpoint_interval and log_checkpoint_timeout because of heavy redo wastage and quick use of redo buffers ?
3) Also the number of redo writes incremented by 83 and the number of log file parallel writes too incremented by 83. So does this mean that even if the user session is not wait for a log file sync, it is giving a call(some async call) to LGWR after each commit to write the redo to file ? (I asked this because the redo writes shown in the below experiment is only 9)
I repeated the experiment after moving the commit out of the loop and saw the following things.
a)No of log file sync's = 1 b)No of REDO Buffers written = 373 c)No of REDO Writes = 9 d) Redo wastage = 3212 (previously it was 22124)
regards
Srivenu
Received on Fri Nov 08 2002 - 07:36:50 CST