Amonte,
Yes you are right, dbwr does write in batches, whenever possible. So
this logic does not apply all the time. It was a maximum number of
possible writes.
I think Tanel's explalanation is more accurate with what's happening
in your case.
What I was trying to say is that there is no direct relationship
between size of redo and amount of time it takes to checkpoint those
changes. So sometimes it may take 2 hours to checkpoint 600mb of redo,
other times it may take 6 seconds, all depending on how many block
changed, and how many ios dbwriter is doing. Note: async IO also plays
a big role here. If you have it on, then dbwr will submit a lot of ios
to the OS. If you have it off (or not working) it will be 1 io, wait
for finish, next io, wait for finish. Of course 1 io could be more
then 1 block.
Where did you check the block size?
--
Christo Kutrovsky
Senior Database/System Administrator
The Pythian Group - www.pythian.com
I blog at http://www.pythian.com/blogs/
On 1/25/07, amonte <ax.mount@xxxxxxxxx> wrote:
> Christo
>
> Are you saying checkpoints write a block per I/O? I thought DBWR write
> blocks in batches and not single blocks. Your theory doesnt sound right
to
> me. I have another database which generates 24GB redo per hour, if I use
> your calculation 24GB will be 50331648 blocks then my I/O time would be
>
> 1000/(50331648/3600) = 0.0715 ms
>
> Isnt that a bit too fast?
>
> TIA
>
> Alex
>
>
>
>
> On 1/24/07, Christo Kutrovsky < kutrovsky.oracle@xxxxxxxxx> wrote:
> > Well, in theory, 600mb of redo log could be 1'228'800 blocks changed.
> > That's 629145600 bytes of redo log, with a redo record been 512 bytes.
> >
> > That's only an approximation, since you could have merged records,
> > multiple changes in a single record and etc.
> >
> > Let's assume a typical IO time of 5 ms. That would be 1228800*5ms =
> > 6'144'000 ms = 6'144 seconds = 1.7 hours.
> >
> > So it could've taken 1.7 hours. And that's been optimistic about the
> > 5ms IO. It could've been 10 ms during busy times.
> >
> > It's not as bad as it sounds.
> >
> > --
> > Christo Kutrovsky
> > Senior Database/System Administrator
> > The Pythian Group - www.pythian.com
> > I blog at http://www.pythian.com/blogs/
> >
> >
> > On 1/18/07, amonte <ax.mount@xxxxxxxxx> wrote:
> > > Hello all
> > >
> > > I have a quite busy Oracle APPS database running in HPUX. Today
during
> peak
> > > hour I saw this in alert
> > >
> > > Thu Jan 18 10:19:50 2007
> > > Beginning log switch checkpoint up to RBA [0x17d1.2.10], SCN:
> > > 0x0784.b14a52c1
> > > Thu Jan 18 10:22:09 2007
> > > Beginning log switch checkpoint up to RBA [ 0x17d2.2.10], SCN:
> > > 0x0784.b14a8673
> > > Thu Jan 18 10:26:18 2007
> > > Beginning log switch checkpoint up to RBA [0x17d3.2.10], SCN:
> > > 0x0784.b14aee22
> > > Thu Jan 18 10:51:32 2007
> > > Beginning log switch checkpoint up to RBA [ 0x17d4.2.10], SCN:
> > > 0x0784.b14d0ddb
> > > Thu Jan 18 11:09:24 2007
> > > Beginning log switch checkpoint up to RBA [0x17d5.2.10], SCN:
> > > 0x0784.b14ea5dd
> > > .........................
> > > Thu Jan 18 11:12:04 2007
> > > Completed checkpoint up to RBA [0x17d1.2.10], SCN: 0x0784.b14a52c1
> > > Thu Jan 18 11:16:19 2007
> > > Completed checkpoint up to RBA [0x17d2.2.10], SCN: 0x0784.b14a8673
> > > Thu Jan 18 11:16:45 2007
> > > Completed checkpoint up to RBA [ 0x17d3.2.10], SCN: 0x0784.b14aee22
> > > Thu Jan 18 11:18:22 2007
> > > Completed checkpoint up to RBA [0x17d4.2.10], SCN: 0x0784.b14d0ddb
> > > Thu Jan 18 11:23:56 2007
> > > Completed checkpoint up to RBA [ 0x17d5.2.10 ], SCN: 0x0784.b14ea5dd
> > >
> > >
> > >
> > > From v$log_histroty I see the log switch frequency
> > >
> > > select * from v$log_history
> > > where FIRST_TIME > ('20070118 090000');
> > >
> > > RECID STAMP THREAD# SEQUENCE#
> FIRST_CHANGE#
> > > FIRST_TIME NEXT_CHANGE#
> > > ---------- ---------- ---------- ---------- ----------------------
> > > --------------- ----------------
> > > 6096 612181190 1 6096
> 8266491016370 20070118
> > > 090018 8266491515585
> > > 6097 612181328 1 6097
> 8266491515585 20070118
> > > 101949 8266491528819
> > > 6098 612181578 1 6098
> 8266491528819 20070118
> > > 102208 8266491555362
> > > 6099 612183092 1 6099
> 8266491555362 20070118
> > > 102618 8266491694555
> > > 6100 612184164 1 6100
> 8266491694555 20070118
> > > 105132 8266491799005
> > > 6101 612185404 1 6101
> 8266491799005 20070118
> > > 110923 8266491936643
> > >
> > >
> > > Redo log are 600MB each.
> > >
> > > How can a checkpoint take so long?
> > >
> > >
> > >
> > > Cheers
> > >
> > > Alex
> > >
> > >
> >
> >
> > --
> > Christo Kutrovsky
> > Senior Database/System Administrator
> > The Pythian Group - www.pythian.com
> > I blog at http://www.pythian.com/blogs/
> >
>
>
--
Christo Kutrovsky
Senior Database/System Administrator
The Pythian Group - www.pythian.com
I blog at http://www.pythian.com/blogs/
