"recover database" pauses for minutes

From: Nick Kean <nick.kean_at_staff.ihug.co.nz>
Date: 31 May 1999 17:17:44 GMT
Message-ID: <slrn7l5h1o.5eu.nick.kean@coffee.ihug.co.nz>

  I'm running 7.3.4 on Solaris 2.5.1 and have just had to recover the database from my hot backup[1]. The redo logs are applied using "auto" but quite often the system pauses for minutes with apparently no activity whatsoever. This is really annoying since it's taking over 3 times longer to restore the logs than it did to create them in the first place.

  A fast restore is critical and next time I have to do this, I don't want to wait and wait and wait ...

  What could be causing this? There are no other users on the machine. If I had to restore a whole days logfiles then I'd really be in shit creek. As it was, I only needed about an hours worth (thank god for small mercies).

ORA-00279: Change 11614465 generated at 06/01/99 00:35:44 needed for thread 1
ORA-00289: Suggestion : /oracle/backup/act1/arch.log/arch_0000014954
ORA-00280: Change 11614465 for thread 1 is in sequence #14954
ORA-00278: Logfile '/oracle/backup/act1/arch.log/arch_0000014953' no longer

needed for this recovery

   [ ... big delay here ... ]
Log applied.

ORA-00279: Change 11614597 generated at 06/01/99 00:36:50 needed for thread 1
ORA-00289: Suggestion : /oracle/backup/act1/arch.log/arch_0000014955
ORA-00280: Change 11614597 for thread 1 is in sequence #14955
ORA-00278: Logfile '/oracle/backup/act1/arch.log/arch_0000014954' no longer

needed for this recovery

  System apparently stopped (iostat):

                                 extended disk statistics 
disk      r/s  w/s   Kr/s   Kw/s wait actv  svc_t  %w  %b 
sd3       0.0  0.2    0.0    1.6  0.0  0.0    2.2   0   0 
sd13      0.0  0.0    0.0    0.0  0.0  0.0    0.0   0   0 
sd15      0.0  0.0    0.0    0.0  0.0  0.0    0.0   0   0 
sd18      0.0  0.2    0.0    1.6  0.0  0.0    1.1   0   0 

  And then it carries on again :
disk      r/s  w/s   Kr/s   Kw/s wait actv  svc_t  %w  %b 
sd3       0.4  0.6    1.2    2.8  0.0  0.0    7.2   0   1 
sd13     130.8 181.6  631.2  726.4  0.5  2.0    8.2  31  84 
sd15      0.0  0.0    0.0    0.0  0.0  0.0    0.0   0   0 
sd18     17.6 46.6  288.8  189.0  0.0  0.2    2.8   0  12 

  Stopped (mpstat) :
CPU minf mjf xcal intr ithr csw icsw migr smtx srw syscl usr sys wt idl   0 69 0 93 57 6 11 1 0 5 0 76 0 4 0 95   1 0 0 0 46 6 14 0 0 0 0 14 0 0 0 100   2 0 0 0 54 5 14 0 0 0 0 12 0 0 0 100   3 0 0 66 38 5 14 0 0 4 0 39 0 1 0 99

  Stopped (vmstat) :
 procs memory page disk faults cpu  r b w swap free re mf pi po fr de sr s3 s1 s1 s1 in sy cs us sy id  0 0 0 1340360 9324 0 104 0 0 0 0 0 0 0 0 0 141 163 54 0 3 97  0 0 0 1340392 9328 0 104 0 0 0 0 0 0 0 0 0 144 168 53 1 2 97

  Running
 0 3 0 1340076 8676 67 85 878 896 895 0 0 0 315 0 79 2610 2767 2683 10 16 74  0 3 0 1340116 8544 67 104 940 965 965 0 0 1 312 2 74 2436 2844 2853 7 17 76  0 1 0 1340340 8368 43 90 762 607 729 0 32 6 281 8 80 2317 2288 2289 6 12 82

[1] recover database until time '1999-06-01:01:12:02';

--
Reality is a cheap substitute for Prozac Received on Mon May 31 1999 - 12:17:44 CDT