Use strace in Linux to peat the Oracle LGWR Process

The strace in Linux can help us track program system calls. LGWR is an important process in Oracle and is responsible for writing redo logs into online redo logs.

Let's try to use strace to peat LGWR behavior.

First, find the LGWR process Number:

1	[oracle@www.bkjia.com ~]$ ps -ef | grep $ORACLE_SID | grep lgwr

2	oracle    5140     1  0 Nov09 ?        00:00:12 ora_lgwr_mydb

When executing commands on a terminal, we are concerned about opening files by LGWR:

 

1	[oracle@www.bkjia.com ~]$ strace -p 5140 2>&1 | grep -i open

Run the following statement in sqlplus to add a new set of online redo logs:

 

1	ALTER DATABASE ADD LOGFILE ('/u02/oradata/mydb/redolog/group04/redo05a.log',

2	'/u02/oradata/mydb/redolog/group04/redo05b.log')

3

SIZE 50m;

Then switch logfile multiple times:

 

1	alter system switch logfile;

2	alter system switch logfile;

3	alter system switch logfile;

4	alter system switch logfile;

5	alter system switch logfile;

6	alter system switch logfile;

In this case, strace has output:

 

01	open("/u02/oradata/mydb/redolog/group04/redo05a.log", O_RDONLY) = 60

02	open("/u02/oradata/mydb/redolog/group04/redo05a.log", O_RDWR|O_SYNC) = 60

03	open("/u02/oradata/mydb/redolog/group04/redo05b.log", O_RDONLY) = 61

04	open("/u02/oradata/mydb/redolog/group04/redo05b.log", O_RDWR|O_SYNC) = 61

05	open("/proc/5164/stat", O_RDONLY)       = 62

06	open("/u01/app/admin/mydb/bdump/alert_mydb.log", O_WRONLY|O_CREAT|O_APPEND, 0664) = 8

07	open("/u01/app/admin/mydb/bdump/alert_mydb.log", O_WRONLY|O_CREAT|O_APPEND, 0664) = 8

08	open("/u01/app/admin/mydb/bdump/alert_mydb.log", O_WRONLY|O_CREAT|O_APPEND, 0664) = 8

09

.......

10

.......

11

.......

We can see that LGWR has opened a new redo group, followed by a bunch of opening and writing operations on the alert file, we can see that LGWR uses the O_SYNC flag for open operations on the online redo log. It is learned from google that this flag is used to bypass the cache of the file system.

Let's take a look at the huge effect of the file system cache and use the dd command to simulate it:

 

01	[ora11g@FWDB ~]$ time dd if=/dev/zero of=/tmp/bigfile.bin bs=1048576 count=2048 ; time sync ;

02	2048+0 records in

03	2048+0 records out

04	2147483648 bytes (2.1 GB) copied, 11.7151 seconds, 183 MB/s

05

06	real    0m11.763s

07	user    0m0.002s

08	sys     0m5.189s

09

10	real    0m9.671s

11	user    0m0.000s

12	sys     0m0.561s

13

14

15	[ora11g@FWDB ~]$ time dd if=/dev/zero of=/tmp/bigfile.bin bs=1048576 count=2048 oflag=sync; time sync ;

16	2048+0 records in

17	2048+0 records out

18	2147483648 bytes (2.1 GB) copied, 17.3505 seconds, 124 MB/s

19

20	real    0m17.900s

21	user    0m0.002s

22	sys     0m6.546s

23

24	real    0m0.150s

25	user    0m0.000s

26	sys     0m0.003s

It can be seen that the file system cache greatly increases the throughput capacity, but data may be lost once the power is down.