Loooong Logical Undo Phase Question

Posted by Paul Koufalis on 19-Jun-2014 10:27

[2014/06/19@07:18:26.941-0600] Begin Physical Redo Phase at 5858304 .

[2014/06/19@07:18:27.329-0600] Physical Redo Phase Completed at blk 5859327 off 16247 upd 0.

[2014/06/19@07:18:27.338-0600] At end of Physical redo, transaction table size is 512.
[2014/06/19@07:18:28.003-0600] Begin Physical Undo 1 transactions at block 5859328 offset 287

[2014/06/19@08:09:46.275-0600] Physical Undo Phase Completed at 4901816 .
[2014/06/19@08:09:46.286-0600] Begin Logical Undo Phase, 1 incomplete transactions are being backed out.
[2014/06/19@08:09:46.295-0600] Logical Undo Phase begin at Block 4901816 Offset 9095.

I know there's no way to know where I am in the logical undo phase...but...If nmon is telling me that I'm reading the BI at 5K/sec, can I guestimate the amount of time it will take to read the entire BI and therefore how long the process will take?

With a 95 Gb BI file, this guestimate comes out to about 5 hours.  However the physical UNDO phase only took about 50 minutes and it seems to have looped through the entire BI (start block 5 859 328; end blocl 4 901 816).

Can anyone add some useful information?

All Replies

Posted by gus on 19-Jun-2014 10:39

logical undo does not read the entire bi file. it only has to go back to wherever the transaction begin note is for the oldest active transaction. it does not have to look at notes from committed transactions. unfortunately, at the moment, there is no way to get an estimate of how much is left. if we numbered the notes from 1 to n for each transaction, then we could know how many notes were left to process. but we don't have that info.

also, logical backout has "jump" notes that it uses to skip over stuff and there was a bug that got fixed recently where that was not working right. sorry but i don't remember what version that bug appeared in or what verions it was removed in.

unlikely that the physical undo read 95 gb. and if it did, there would not be much left for the logical undo to process. the undo phase switches from physical to logical when it needs to. it does not start over when it switches, but keeps going from where it was when the switch took place.

Posted by Paul Koufalis on 19-Jun-2014 10:48

This makes some sense.  If the physical undo went backwards from 5 859 328 to 4 901 816, that works out to 51 minutes at 5KB/s which matches the log file. The BI was fairly small to begin with, so assuming logical undo has to read the rest of the BI we're down to 261 minutes to read 80 Gb (4 901 816 blocks).

Posted by Thomas Mercer-Hursh on 19-Jun-2014 10:52

95GB BI File????

Posted by Paul Koufalis on 19-Jun-2014 10:58

The customer put in a code change that opened a transaction then went into a freak-out loop.  There is no long-tx monitoring nor BI growth monitoring so it just kept growing.  Obviously no bistall either.

Posted by Thomas Mercer-Hursh on 19-Jun-2014 11:47

Wow!

Posted by gus on 19-Jun-2014 13:05

>> assuming logical undo has to read the rest of the BI we're down to 261 minutes to read 80 Gb (4 901 816 blocks)

possible but not likely. note also that during physical undo, (almost) every note gets processed (i.e. undone) but during logical undo only some notes need to be processed, even for the case where every bi block has to be read. so the logical undo phase can be faster then the physical but ymmv depending on the ration of active to committed transactions.

Posted by Paul Koufalis on 19-Jun-2014 13:14

The physical undo phase took 51 minutes and the logical undo phase has been running for just over 4h.

Posted by Paul Koufalis on 19-Jun-2014 13:30

Logical Undo finished in 4h16 minutes which matches the estimates discussed here.  The original BI file was 1.7 Gb so the logical undo read from 80 Gb back to about 2 Gb to find the little tiny note.

That's my story and I'm sticking to it!

This thread is closed