LFPW Parameters

During some recent investigations into “log file parallel write” (LFPW) performance I found myself looking at the Oracle 11.2 Database Reference and wondering about P2 of this wait event. In case you’re not familiar with the parameters they are:

Parameter     Description
------------  ------------------------------
files         Number of files to be written
blocks        Number of blocks to be written
requests      Number of I/O requests
------------  ------------------------------

File is obvious, the number of log file members in the current redo log group, but for the other two parameters I wasn’t sure if it is the number of blocks/request per file or in total. I assumed total, but wanted to be sure so did a quick bit of searching. This led me to OraDBPedia where I read,

P2=The number of redo blocks to be written to each log member.

and

P3=Total number of I/O requests needed to satisfy the write load (i.e. P2).

For whatever reason, I didn’t feel 100% happy to accept this so did a quick test in 11.2.0.2 XE as shown below.

Test Details:

1. Enable tracing of LGWR
2. Run “alter system switch logfile” to cause LGWR to flush the redo buffer (not shown in output below)
3. Run small insert statement
4. Commit
5. Examine trace file

Starting off with the default in XE of 1 member per group:

14:01:19 SQL> insert into t (c1, c2, c3) values (1,'DELETE', sysdate);

1 row created.

14:01:23 SQL> commit;

Commit complete.

14:01:27 SQL>

Looking at the 10046 trace reveals:

*** 2011-09-29 14:01:27.315
WAIT #0: nam='log file parallel write' ela= 374 files=1 blocks=2 requests=1 obj#=-1 tim=1481335308118

Adding another member to each of the 2 groups giving 2 members per group:

14:01:27 SQL> insert into t (c1, c2, c3) values (1,'DELETE', sysdate);

1 row created.

14:04:48 SQL> commit;

Commit complete.

14:04:53 SQL>

Looking at the 10046 trace reveals:

*** 2011-09-29 14:04:52.477
WAIT #0: nam='rdbms ipc message' ela= 2969787 timeout=300 p2=0 p3=0 obj#=-1 tim=1481538543689
WAIT #0: nam='rdbms ipc message' ela= 30043 timeout=3 p2=0 p3=0 obj#=-1 tim=1481538574024
WAIT #0: nam='rdbms ipc message' ela= 567670 timeout=300 p2=0 p3=0 obj#=-1 tim=1481539141991
WAIT #0: nam='log file parallel write' ela= 550 files=2 blocks=4 requests=2 obj#=-1 tim=1481539142779

Adding another member to each of the 2 groups giving 3 members per group:

14:04:53 SQL> insert into t (c1, c2, c3) values (1,'DELETE', sysdate);

1 row created.

14:07:51 SQL> commit;

Commit complete.

14:07:53 SQL>

Looking at the 10046 trace reveals:

*** 2011-09-29 14:07:53.980
WAIT #0: nam='rdbms ipc message' ela= 2560082 timeout=300 p2=0 p3=0 obj#=-1 tim=1481718344261
WAIT #0: nam='log file parallel write' ela= 1658 files=3 blocks=6 requests=3 obj#=-1 tim=1481718346216
WAIT #0: nam='rdbms ipc message' ela= 438069 timeout=44 p2=0 p3=0 obj#=-1 tim=1481718784548

Adding another member to each of the 2 groups giving 4 members per group:

14:07:53 SQL> insert into t (c1, c2, c3) values (1,'DELETE', sysdate);

1 row created.

14:09:48 SQL> commit;

Commit complete.

14:09:51 SQL>

Looking at the 10046 trace reveals:

*** 2011-09-29 14:09:51.687
WAIT #0: nam='rdbms ipc message' ela= 1445500 timeout=300 p2=0 p3=0 obj#=-1 tim=1481834980859
WAIT #0: nam='log file parallel write' ela= 1910 files=4 blocks=8 requests=4 obj#=-1 tim=1481834983045

I see the above a conclusive evidence that both blocks (p2) and requests (p3) are the total rather than “per file”.

Maybe things have changed since the OraDBPedia articles was originally written, but I’ve contacted the guys behind the site and expect the page to be updated shortly.