Monday, January 3, 2011

Oracle Log Writer(LGWR) process on an commit

What I wanted to understand here was the behaviour of the Log Writer(LGWR) process when a "commit" is issued at the sqlplus prompt after inserting some date onto the table;

Here is the list of all the log files
SQL> select member from v$logfile;

MEMBER
--------------------------------------------------------------------------------
/u02/app/oracle/oradata/ABC/onlinelog/o1_mf_3_6kt8lo0w_.log
/u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_3_6kt8lomz_.log
/u02/app/oracle/oradata/ABC/onlinelog/o1_mf_2_6kt8lms1_.log
/u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_2_6kt8lnf2_.log
/u02/app/oracle/oradata/ABC/onlinelog/o1_mf_1_6kt8lkp2_.log
/u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_1_6kt8lm49_.log

6 rows selected.

SQL>
lsof tells us the PID of the process that has opened the file, and also the FD (file descriptor) number.
[root@isvx3 ~]# lsof /u02/app/oracle/oradata/ABC/onlinelog/o1_mf_3_6kt8lo0w_.log
COMMAND   PID   USER   FD   TYPE DEVICE     SIZE     NODE NAME
oracle  32011 oracle   22u   REG    8,3 52429312 68747408 /u02/app/oracle/oradata/ABC/onlinelog/o1_mf_3_6kt8lo0w_.log
[root@isvx3 ~]# lsof /u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_3_6kt8lomz_.log
COMMAND   PID   USER   FD   TYPE DEVICE     SIZE     NODE NAME
oracle  32011 oracle   23u   REG    8,3 52429312 68747409 /u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_3_6kt8lomz_.log
[root@isvx3 ~]# lsof /u02/app/oracle/oradata/ABC/onlinelog/o1_mf_2_6kt8lms1_.log
COMMAND   PID   USER   FD   TYPE DEVICE     SIZE     NODE NAME
oracle  32011 oracle   20u   REG    8,3 52429312 68747406 /u02/app/oracle/oradata/ABC/onlinelog/o1_mf_2_6kt8lms1_.log
[root@isvx3 ~]# lsof /u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_2_6kt8lnf2_.log
COMMAND   PID   USER   FD   TYPE DEVICE     SIZE     NODE NAME
oracle  32011 oracle   21u   REG    8,3 52429312 68747407 /u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_2_6kt8lnf2_.log
[root@isvx3 ~]# lsof /u02/app/oracle/oradata/ABC/onlinelog/o1_mf_1_6kt8lkp2_.log
COMMAND   PID   USER   FD   TYPE DEVICE     SIZE     NODE NAME
oracle  32011 oracle   18u   REG    8,3 52429312 68747402 /u02/app/oracle/oradata/ABC/onlinelog/o1_mf_1_6kt8lkp2_.log
[root@isvx3 ~]# lsof /u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_1_6kt8lm49_.log
COMMAND   PID   USER   FD   TYPE DEVICE     SIZE     NODE NAME
oracle  32011 oracle   19u   REG    8,3 52429312 68747405 /u02/app/oracle/flash_recovery_area/ABC/onlinelog/o1_mf_1_6kt8lm49_.log
[root@isvx3 ~]#
I checked to make sure 32011 was indeed the log writer process.
[root@isvx3 ~]# ps -ef | grep lgwr
oracle    9435     1  0  2010 ?        00:00:00 asm_lgwr_+ASM
root     13979 13779  0 17:20 pts/3    00:00:00 grep lgwr
oracle   32011     1  0  2010 ?        00:00:00 ora_lgwr_abc
Then I started stracing the log writer process and redirecting the output to a file /tmp/lgwr.txt
[root@isvx3 ~]# strace -o /tmp/lgwr.txt -p 32011
Process 32011 attached - interrupt to quit
Next I did an intert into my movies table to see if that causes the log writer process to do anything.
 SQL> insert into movies values (12, 'Masoon', 'naseeruddin Shah', 'Shabana Azmi',1983);

1 row created.

SQL> commit;

Commit complete.
On another window tailed the output from the lgwr
[root@isvx3 ~]# tail -f /tmp/lgwr.txt 
I observed that there were pwrite() calls made by LGWR right after the commit statement was issued at the sql prompt.

Next, I updated the last inset to change 'naseeruddin Shah' to Naseeruddin Shah'
SQL> update movies set actor = 'Naseeruddin Shah' where actor = 'naseeruddin Shah';

1 row updated.
The following pwrites were seen in the strace output after the update statement
[root@isvx3 ~]# cat /tmp/lgwr.txt | grep pwrite
pwrite(24, "\1\"\0\0\177\17\0\0\22\0\0\0\20\200!\177<\2\0\0\5\0\0\0\344\375\22\0\1\0\6\0"..., 1024, 2031104) = 1024
pwrite(25, "\1\"\0\0\177\17\0\0\22\0\0\0\20\200!\177<\2\0\0\5\0\0\0\344\375\22\0\1\0\6\0"..., 1024, 2031104) = 1024
Then I went on to commit the change
SQL> commit;
Commit complete. On enter the commit, the following pwrite was made to the LGWR process
pwrite(24, "\1\"\0\0\201\17\0\0\22\0\0\0\20\200O\244\214\0\0\0\5\0\0\0\357\375\22\0\1\0\0\0"..., 512, 2032128) = 512
pwrite(25, "\1\"\0\0\201\17\0\0\22\0\0\0\20\200O\244\214\0\0\0\5\0\0\0\357\375\22\0\1\0\0\0"..., 512, 2032128) = 512

No comments: