RE: lgwr/dbw0 did not issue pwrite64 sys call

From: D'Hooge Freek <Freek.DHooge_at_uptime.be>
Date: Sun, 27 Nov 2011 09:43:25 +0100
Message-ID: <4814386347E41145AAE79139EAA398981939EB82EE_at_ws03-exch07.iconos.be>



Chen,

During the time you traced the lgwr process, it has not written any data. Most time was spend with the read system call, followed by the semtimedop (semaphore operation). To know from where it is reading you would need to retrace the process without the -c flag and check which open call has returned the file descriptor you see in the read call. I think this can also be a memory structure (maybe reads from the redo log buffer). But I'm not very sure about this.

The note you referenced in your other mail puzzles me, as I always thought that all db processes are reading and writing directly to and from the database files and that asmlib is only responsible for the discovery and stamping of the asm disks.

I don't have an installation with asmlib to test myself, so could you trace a service process when it does some io (for example a large full table scan). Best is to trace the process directly after it has been started (certainly before the full table scan is started), so you see also the open calls for the datafiles (which will show you which flags are used).

Kind regards,

Freek D'Hooge
Uptime
Oracle Database Administrator
email: freek.dhooge_at_uptime.be
tel +32(0)3 451 23 82
http://www.uptime.be
disclaimer: www.uptime.be/disclaimer

---
From: Sidney Chen [mailto:huanshengchen_at_gmail.com] 
Sent: zondag 27 november 2011 3:59
To: D'Hooge Freek
Cc: oracle-l_at_freelists.org
Subject: Re: lgwr/dbw0 did not issue pwrite64 sys call

Freek,

There is no AIO system call, io_submit and io_getevents. I wonder if there any way to identify which process is actually take care the Physical IO.

oracle   16376     1  0 Nov14 ?        00:16:36 ora_lgwr_testsid
$ strace -c -f -S time -p 16376
Process 16376 attached - interrupt to quit
Process 16376 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------

 73.72    0.116262         222       523           read
 20.97    0.033069         109       304        59 semtimedop
  2.24    0.003530          14       260           kill
  1.89    0.002981           2      1199           times
  1.06    0.001674           8       203           semctl
  0.04    0.000068           1        58           getrusage
  0.03    0.000054          14         4           semop
  0.02    0.000036          12         3           open
  0.01    0.000009           9         1           sendmsg
  0.00    0.000005           2         3           close
  0.00    0.000003           1         4           rt_sigprocmask
  0.00    0.000003           3         1         1 rt_sigreturn
  0.00    0.000003           2         2           setitimer
------ ----------- ----------- --------- --------- ---------------- 100.00    0.157697                  2565        60 total -- Regards Sidney Chen -- http://www.freelists.org/webpage/oracle-l
Received on Sun Nov 27 2011 - 02:43:25 CST

Original text of this message