Redo log wait

[Former Member]

Dear All,

We are usinf ecc5 ans the databse oacle 9i on wondows 2003I have notice that the

Redo log wait S has been suddenly increase in number   690

Please suggest what si the problem and to solve it.

Data buffer

Size kb 1,261,568

Quality % 96.2

Reads 4,234,462,711

Physical reads 160,350,516

writes 3,160,751

Buffer busy waits 1,117,697

Buffer wait time s 3,507

Shared Pool

Size kb 507,904

DD-Cache quality % 84.3

SQL Area getratio % 95.6

pinratio % 98.8

reloads/pins % 0.0297

Log buffer

Size kb 1,176

Entries 11,757,027

Allocation retries 722

Alloc fault rate % 0.0

*Redo log wait      s            690*

Log files (in use) 8( 😎

Calls

User calls 41,615,763

commits 367,243

rollbacks 7,890

Recursive calls 100,067,593

Parses 7,822,590

User/Recursive calls 0.4

Reads / User calls 101.8

Time statistics

Busy wait time s 697,392

CPU time s 42,505

Time/User call ms 18

Sessions busy % 9.26

CPU usage % 4.51

CPU count 2

Redo logging

Writes 1,035,582

OS-Blocks written 14,276,056

Latching time s 1

Sessions busy % 9.26

CPU usage % 4.51

CPU count 2

Redo logging

Writes 1,035,582

OS-Blocks written 14,276,056

Latching time s 1

Write time s 806

Mb written 6,574

Table scans & fetches

Short table scans 607,891

Long table scans 32,468

Fetch by rowid 1,620,054,083

by continued row 761,131

Sorts

Memory 3,046,669

Disk 32

Rows sorted 446,593,854

Regards,

Shiva

[stefan_koehler · Accepted solution]

Hello Shiva,

please take a look at this paper: http://www.mysaptuning.com/SAP%20TuningHandbook%20-%20ORACLE.pdf

Regards

Stefan

[Former Member · Accepted solution]

Thanks Stefan i will check and send you details of my system .

Regards,

[Former Member · Accepted solution]

Hi Stefan,

As per the doc you have suggest. The details are as following.

In the day there is only 24 log switch , but in hour there is no more than 10 to 15 as per doc ,so ti is very less.

The DD-Cache quality % 84.1 is less

The elapsed time since start

Elapsed since start (s) 540,731

Log buffer

Size kb 1,176

Entries 13,449,901

Allocation retries 767

Alloc fault rate % 0.0

*Redo log wait      s            696*

Log files (in use) 8( 😎

Check DB Wait times

TCode ST04->Detail Analysis Menu->Wait Events

Statistics on total waits for an event

Elapsed time: 985 s

since reset at 09:34:06

Type Client Sessions Busy wait Total wait Busy wait

time (ms) time (ms) time (%)

USER User 40 1,028,710 17,594,230 5.85

BACK ARC0 1 2,640 1,264,410 0.21

BACK ARC1 1 540 1,020,400 0.05

BACK CKPT 1 950 987,490 0.10

BACK DBW0 1 130 983,920 0.01

BACK LGWR 1 160 986,430 0.02

BACK PMON 1 0 987,000 0.00

BACK RECO 1 10 1,800,010 0.00

BACK SMON 1 3,820 1,179,410 0.32

Disk based sorts

Sorts

Memory 3,443,693

Disk 41

Rows sorted 921,591,847

Check DB Shared Pool Quality

Shared Pool

Size kb 507,904

DD-Cache quality % 84.1

SQL Area getratio % 95.6

pinratio % 98.8

reloads/pins % 0.0278

V$LOGHIST

THREAD# SEQUENCE# FIRST_CHANGE# FIRST_TIME SWITCH_CHANGE#

1 31612 381284375 2008/11/13 00:01:29 381293843

1 31613 381293843 2008/11/13 00:12:12 381305142

1 31614 381305142 2008/11/13 03:32:39 381338724

1 31615 381338724 2008/11/13 06:29:21 381362057

1 31616 381362057 2008/11/13 07:00:39 381371178

1 31617 381371178 2008/11/13 07:13:01 381457916

1 31618 381457916 2008/11/13 09:26:17 381469012

1 31619 381469012 2008/11/13 10:27:19 381478636

1 31620 381478636 2008/11/13 10:59:54 381488508

1 31621 381488508 2008/11/13 11:38:33 381498759

1 31622 381498759 2008/11/13 12:05:14 381506545

1 31623 381506545 2008/11/13 12:33:48 381513732

1 31624 381513732 2008/11/13 13:08:10 381521338

1 31625 381521338 2008/11/13 13:50:15 381531371

1 31626 381531371 2008/11/13 14:38:36 381540689

1 31627 381540689 2008/11/13 15:02:19 381549493

1 31628 381549493 2008/11/13 15:43:39 381556307

1 31629 381556307 2008/11/13 16:07:47 381564737

1 31630 381564737 2008/11/13 16:39:45 381571786

1 31631 381571786 2008/11/13 17:07:07 381579026

1 31632 381579026 2008/11/13 17:37:26 381588121

1 31633 381588121 2008/11/13 18:28:58 381595963

1 31634 381595963 2008/11/13 20:00:41 381602469

1 31635 381602469 2008/11/13 22:23:20 381612866

1 31636 381612866 2008/11/14 00:01:28 381622652

1 31637 381622652 2008/11/14 00:09:52 381634720

1 31638 381634720 2008/11/14 03:32:00 381688156

1 31639 381688156 2008/11/14 07:00:30 381703441

14.11.2008 Log File information from control file 10:01:32

Group Thread Sequence Size Nr of Archive First Time 1st SCN

Nr Nr Nr (bytes) Members Status Change Nr in log

1 1 31638 52428800 2 YES INACTIVE 381634720 2008/11/14 03:32:00

2 1 31639 52428800 2 YES INACTIVE 381688156 2008/11/14 07:00:30

3 1 31641 52428800 2 NO CURRENT 381783353 2008/11/14 09:50:09

4 1 31640 52428800 2 YES ACTIVE 381703441 2008/11/14 07:15:07

Regards,

[stefan_koehler · Accepted solution]

Hello Shiva,

please post the content of the view V$SYSTEM_EVENT.

ST04 => Detail analysis menu => Display V$Tables => V$SYSTEM_EVENT

Regards

Stefan

[Former Member · Accepted solution]

Hi Stefan,

Please find the view V$SYSTEM_EVENT. sorry boss it is comming like this only.

Event Total waits Total timeouts Wait time (ms) Avg. wait. (ms)

SQL*Net message from client 51,494,030 0 8,961,192,790 170

rdbms ipc message 2,031,527 574,887 3,223,019,090 1,590

db file sequential read 125,236,386 0 706,397,710 10

pmon timer 190,880 190,871 564,375,540 2,960

smon timer 2,019 1,788 540,953,370 267,930

library cache lock 18,176 18,119 54,442,840 3,000

db file scattered read 8,059,562 0 26,275,960 0

buffer busy waits 1,905,569 13 6,978,920 0

db file parallel read 446,199 0 6,109,620 10

control file sequential read 330,105 0 1,649,070 0

control file parallel write 195,093 0 788,300 0

log file sync 662,222 3 701,990 0

log file switch completion 1,037 614 700,120 680

SQL*Net more data to client 15,651,686 0 579,510 0

enqueue 530 101 448,050 850

log file sequential read 9,254 0 379,110 40

latch free 79,092 11,743 268,990 0

db file parallel write 69,796 0 231,230 0

direct path read 46,681 0 152,370 0

log file parallel write 1,211,227 0 117,970 0

SQL*Net message to client 51,494,098 0 79,870 0

library cache pin 258 20 71,030 280

rdbms ipc reply 3,990 0 31,000 10

SQL*Net more data from client 1,558,097 0 30,510 0

SQL*Net break/reset to client 100,559 0 20,770 0

library cache load lock 31 4 12,510 400

control file heartbeat 1 1 3,990 3,990

db file single write 2,330 0 3,390 0

direct path write 16,237 0 2,220 0

row cache lock 16 0 2,190 140

LGWR wait for redo copy 913 129 1,400 0

switch logfile command 6 0 1,310 220

control file single write 78 0 720 10

reliable message 1 0 470 470

log buffer space 4 0 370 90

log file single write 678 0 350 0

async disk IO 4,121 0 80 0

undo segment extension 21,669 21,667 20 0

refresh controlfile command 1 0 10 10

instance state change 2 0 0 0

buffer deadlock 9 9 0 0

TOTAL 260,844,170 819,969 14,096,024,760 282,860

Regards,

[stefan_koehler · Accepted solution]

Hi Shiva,

thanks for the ouput ... take a look at here

Event	Total waits	Total timeouts	Wait time (ms)	Avg. wait. (ms)
log file switch completion	1,037	614	700,12	680

The normal cause of a log switch is when a process generating redo is unable to allocate space in the log buffer, because there is insufficient space left in the current log file. That process posts LGWR to perform a log switch, and the session sleeps on a log file switch completion wait event.

Please

Regards

Stefan

[Former Member · Accepted solution]

Thank Stefan ,Can you please tell me the step to solve the problem it will be very helpful.

Regards,

Shiva

[stefan_koehler · Accepted solution]

Hello Shiva,

i think you missunderstood something.

540731 (Elapsed since start) / 300 = 1802

Your redologtime => 696

So now if you follow the suggestion from the paper:

> Redo log wait time should be smaller then the elapsed time since DB start / 300 (5 minutes).

It should be fine - the other thing that i have pointed (wait event - log file switch completion) is that you have many timeouts and a high average of wait time. This can be caused by a short massive redolog switching. But for this you can take a look by your own.

To be honest, i am not very fimiliar with the ST04 and i used STATSPACK or AWR for analysis, because of the better time range observation. The event that i have mentioned is since startup.

Regards

Stefan

[Former Member · Accepted solution]

Hi Stefan,

Thanks a lot for you help.

Regards,

Shiva