Solved

Expected Log Write Time

Posted on 2012-03-15
19
1,225 Views
Last Modified: 2012-03-28
My log writer trace file shows certain hours where Oracle is issuing warning on log write times.
Warning: log write time 4990ms, size 105KB
*** 2012-03-14 23:52:25.948
Warning: log write time 4130ms, size 95KB
*** 2012-03-14 23:52:32.629
Warning: log write time 6680ms, size 425KB
*** 2012-03-14 23:52:57.560
Warning: log write time 1100ms, size 1KB
*** 2012-03-14 23:52:59.406
Warning: log write time 1850ms, size 25KB

Anybody know what range in terms of time is considered reasonable?
0
Comment
Question by:xoxomos
19 Comments
 
LVL 23

Expert Comment

by:David
ID: 37726437
Unfortunately, your examples are all taken from a 35 second window, so we cannot guess if you have a pattern or just a random act of electrons.  I'd like to see a better log sample, as well as the undo log sizing before I say more.
0
 

Author Comment

by:xoxomos
ID: 37726686
Warning: log write time 670ms, size 15KB
*** 2012-03-14 23:41:09.686
Warning: log write time 650ms, size 44KB
*** 2012-03-14 23:41:13.499
Warning: log write time 560ms, size 33KB
*** 2012-03-14 23:41:14.611
Warning: log write time 1110ms, size 41KB
*** 2012-03-14 23:41:15.218
Warning: log write time 600ms, size 118KB
*** 2012-03-14 23:41:18.037
Warning: log write time 1830ms, size 181KB
*** 2012-03-14 23:41:26.497
Warning: log write time 650ms, size 2KB
*** 2012-03-14 23:41:55.942
Warning: log write time 660ms, size 5KB
*** 2012-03-14 23:41:56.593
Warning: log write time 650ms, size 76KB
*** 2012-03-14 23:42:28.664
Warning: log write time 1080ms, size 13KB
*** 2012-03-14 23:42:32.287
Warning: log write time 3620ms, size 142KB
*** 2012-03-14 23:42:39.323
Warning: log write time 7030ms, size 201KB
*** 2012-03-14 23:42:41.427
Warning: log write time 2100ms, size 75KB
*** 2012-03-14 23:42:43.625
Warning: log write time 1970ms, size 70KB
*** 2012-03-14 23:42:55.727
Warning: log write time 830ms, size 1KB
*** 2012-03-14 23:43:06.016

Warning: log write time 5130ms, size 81KB
*** 2012-03-14 23:37:21.997
Warning: log write time 13060ms, size 542KB
*** 2012-03-14 23:37:26.248
Warning: log write time 4240ms, size 3468KB
*** 2012-03-14 23:37:28.400
Warning: log write time 2140ms, size 1223KB
*** 2012-03-14 23:37:36.152
Warning: log write time 1630ms, size 1KB
*** 2012-03-14 23:38:28.250
Warning: log write time 52060ms, size 15028KB
*** 2012-03-14 23:38:29.001
Warning: log write time 730ms, size 475KB
*** 2012-03-14 23:38:29.588
Warning: log write time 590ms, size 721KB
*** 2012-03-14 23:38:49.022
Warning: log write time 660ms, size 22KB
*** 2012-03-14 23:38:53.658
Warning: log write time 1870ms, size 52KB
*** 2012-03-14 23:38:58.756
Warning: log write time 5100ms, size 171KB
*** 2012-03-14 23:39:01.082
Warning: log write time 2320ms, size 241KB
*** 2012-03-14 23:39:30.083
Warning: log write time 760ms, size 51KB
*** 2012-03-14 23:39:32.784
Warning: log write time 2700ms, size 69KB
*** 2012-03-14 23:39:39.241
Warning: log write time 6450ms, size 295KB
*** 2012-03-14 23:39:40.071
Warning: log write time 820ms, size 709KB
*** 2012-03-14 23:39:40.756
Warning: log write time 600ms, size 36KB
*** 2012-03-14 23:39:42.781
Warning: log write time 590ms, size 4KB
*** 2012-03-14 23:40:04.558
Warning: log write time 1160ms, size 69KB
*** 2012-03-14 23:40:08.043
Warning: log write time 3490ms, size 143KB
*** 2012-03-14 23:40:10.835
Warning: log write time 2790ms, size 385KB
*** 2012-03-14 23:40:11.575
Warning: log write time 740ms, size 240KB
*** 2012-03-14 23:40:35.722
Warning: log write time 1680ms, size 73KB
*** 2012-03-14 23:40:40.160
Warning: log write time 4440ms, size 71KB

*** 2012-03-14 23:34:15.241
Warning: log write time 900ms, size 33KB
*** 2012-03-14 23:35:06.058
Warning: log write time 1010ms, size 2KB
*** 2012-03-14 23:35:14.370
Warning: log write time 630ms, size 0KB
*** 2012-03-14 23:35:18.937
Warning: log write time 4570ms, size 68KB
*** 2012-03-14 23:35:26.926
Warning: log write time 7990ms, size 293KB
*** 2012-03-14 23:35:35.988
Warning: log write time 9060ms, size 393KB
*** 2012-03-14 23:35:36.640
Warning: log write time 650ms, size 589KB
*** 2012-03-14 23:35:51.910
Warning: log write time 1390ms, size 17KB
*** 2012-03-14 23:35:56.742
Warning: log write time 4830ms, size 64KB
*** 2012-03-14 23:36:00.912
Warning: log write time 4160ms, size 258KB
*** 2012-03-14 23:36:03.163
Warning: log write time 1540ms, size 111KB
*** 2012-03-14 23:36:08.024
Warning: log write time 4760ms, size 136KB
*** 2012-03-14 23:36:09.299
Warning: log write time 1270ms, size 302KB
*** 2012-03-14 23:36:26.394
Warning: log write time 510ms, size 18KB
*** 2012-03-14 23:36:28.216
Warning: log write time 1820ms, size 32KB
*** 2012-03-14 23:36:29.275
Warning: log write time 1060ms, size 92KB
*** 2012-03-14 23:36:31.469
Warning: log write time 1990ms, size 24KB
*** 2012-03-14 23:36:33.396
Warning: log write time 1930ms, size 116KB
*** 2012-03-14 23:36:34.182
Warning: log write time 770ms, size 145KB
*** 2012-03-14 23:36:37.866
Warning: log write time 1540ms, size 23KB
*** 2012-03-14 23:36:38.536
Warning: log write time 670ms, size 108KB
*** 2012-03-14 23:36:44.150
Warning: log write time 530ms, size 93KB
*** 2012-03-14 23:37:08.931
Warning: log write time 5130ms, size 81KB
*** 2012-03-14 23:37:21.997

Warning: log write time 700ms, size 21KB
*** 2012-03-14 23:31:38.068
Warning: log write time 510ms, size 18KB
*** 2012-03-14 23:31:39.504
Warning: log write time 1430ms, size 24KB
*** 2012-03-14 23:31:40.854
Warning: log write time 1350ms, size 107KB
*** 2012-03-14 23:31:43.131
Warning: log write time 2270ms, size 49KB
*** 2012-03-14 23:31:45.921
Warning: log write time 2790ms, size 141KB
*** 2012-03-14 23:31:47.584
Warning: log write time 1660ms, size 144KB
*** 2012-03-14 23:32:06.162
Warning: log write time 810ms, size 1KB
*** 2012-03-14 23:32:14.728
Warning: log write time 540ms, size 58KB
*** 2012-03-14 23:32:22.774
Warning: log write time 730ms, size 13KB
*** 2012-03-14 23:32:24.126
Warning: log write time 1350ms, size 77KB
*** 2012-03-14 23:32:24.687
Warning: log write time 560ms, size 78KB
*** 2012-03-14 23:32:25.895
Warning: log write time 770ms, size 30KB
*** 2012-03-14 23:32:27.772
Warning: log write time 510ms, size 3KB
*** 2012-03-14 23:32:37.631
Warning: log write time 1380ms, size 36KB
*** 2012-03-14 23:32:38.281
Warning: log write time 650ms, size 61KB
*** 2012-03-14 23:32:46.552
Warning: log write time 830ms, size 11KB
*** 2012-03-14 23:32:47.061
Warning: log write time 500ms, size 53KB
*** 2012-03-14 23:32:50.646
Warning: log write time 1110ms, size 5KB
*** 2012-03-14 23:34:09.350
Warning: log write time 860ms, size 5KB
*** 2012-03-14 23:34:11.571
Warning: log write time 2200ms, size 66KB
*** 2012-03-14 23:34:12.429
Warning: log write time 860ms, size 138KB
*** 2012-03-14 23:34:13.568
Warning: log write time 1140ms, size 103KB
*** 2012-03-14 23:34:15.241
Warning: log write time 900ms, size 33KB

*** 2012-03-14 23:29:25.601
Warning: log write time 530ms, size 2KB
*** 2012-03-14 23:29:36.006
Warning: log write time 1120ms, size 2KB
*** 2012-03-14 23:29:37.045
Warning: log write time 1040ms, size 14KB
*** 2012-03-14 23:29:38.553
Warning: log write time 1510ms, size 29KB
*** 2012-03-14 23:29:39.251
Warning: log write time 700ms, size 20KB
*** 2012-03-14 23:29:41.123
Warning: log write time 600ms, size 5KB
*** 2012-03-14 23:29:42.248
Warning: log write time 1120ms, size 25KB
*** 2012-03-14 23:29:44.436
Warning: log write time 1580ms, size 37KB
*** 2012-03-14 23:29:45.717
Warning: log write time 1280ms, size 44KB
*** 2012-03-14 23:29:47.820
Warning: log write time 1830ms, size 26KB
*** 2012-03-14 23:29:50.189
Warning: log write time 790ms, size 169KB
*** 2012-03-14 23:30:10.981
Warning: log write time 570ms, size 9KB
*** 2012-03-14 23:30:13.061
Warning: log write time 2080ms, size 35KB
*** 2012-03-14 23:30:13.590
Warning: log write time 530ms, size 129KB
*** 2012-03-14 23:30:14.407
Warning: log write time 810ms, size 43KB
*** 2012-03-14 23:30:19.015
Warning: log write time 630ms, size 24KB
*** 2012-03-14 23:30:25.872 56967 kcrr.c
0
 

Author Comment

by:xoxomos
ID: 37726716
ACTUAL UNDO SIZE [MByte] UNDO RETENTION [Sec]      NEEDED UNDO SIZE [MByte]
------------------------ ------------------------- ------------------------
                    2048 900                                     54.2109375
0
 
LVL 8

Accepted Solution

by:
ReliableDBA earned 250 total points
ID: 37726824
Certainly more than a sec (1000ms) is not acceptable from my experience.
What is the storage for your online redo logs?
Hope you are not using RAID 5.
0
 
LVL 36

Expert Comment

by:Geert Gruwez
ID: 37728123
check in the virusscanner for the exclusions of the datafiles, redologs and controlfiles
0
 

Author Comment

by:xoxomos
ID: 37730555
No, we are not on RAID5.  I am suspecting some sort of i/o contention.
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37730728
Do you see any CPU spent for i/o?
0
 

Author Comment

by:xoxomos
ID: 37731006
Very little.  Most times there's a big surplus of CPU :-)
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37731035
Are you using AMM?
What is the size of your log_buffer?
0
PRTG Network Monitor: Intuitive Network Monitoring

Network Monitoring is essential to ensure that computer systems and network devices are running. Use PRTG to monitor LANs, servers, websites, applications and devices, bandwidth, virtual environments, remote systems, IoT, and many more. PRTG is easy to set up & use.

 

Author Comment

by:xoxomos
ID: 37731092
No AMM.  
log_buffer                           integer
16006144
SQL>
Interesting you'd mention that.  As I understand now this log_buffer is pretty much assigned by Oracle so that's the default.  I tried to make it smaller but no.  The other option I had considered since I could not make log_buffer smaller was make redo logs larger.  Currently they are 100mb.
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37731566
Irrespective of redo log size, i had seen Oracle rotating the redo logs at smaller sizes.
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37731567
Checking further to see if i post anything that will help you.
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37738939
also did you do a truss on the lgwr process and see the timings for thread_post and thread_Wait?
0
 

Author Comment

by:xoxomos
ID: 37739105
No.
"Word of caution, don't truss LGWR or any background process unless it is absolutely necessary. You can accidentally cause performance issues, worse yet, ..." :-)
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37739117
Thanks.
I think we use truss only if there is a performance issue. :)
0
 

Author Comment

by:xoxomos
ID: 37739185
Right now we're not having performance issue and it's finals week :-)
The learning system was down most of yesterday because someone felt the need to move from 3Par to NetApp, they could not wait a week and needless to say the move did not go perfectly so i'm avoiding anything that might have an impact that will have the students even madder. :-)
0
 
LVL 8

Expert Comment

by:ReliableDBA
ID: 37739456
Oh! ok.
Ya. Obviously you know best about your environment.
Will see what best inputs can be provided here.
0
 

Author Comment

by:xoxomos
ID: 37761979
Quarter ends Wed.
0
 

Author Closing Comment

by:xoxomos
ID: 37778845
Thanks,
It appears something unusual was happening during that time.  The data center was moving, cables were being dehooked , rehooked and re-rehooked etc but now things seem to have returned to normal.
0

Featured Post

PRTG Network Monitor: Intuitive Network Monitoring

Network Monitoring is essential to ensure that computer systems and network devices are running. Use PRTG to monitor LANs, servers, websites, applications and devices, bandwidth, virtual environments, remote systems, IoT, and many more. PRTG is easy to set up & use.

Join & Write a Comment

Suggested Solutions

How to Create User-Defined Aggregates in Oracle Before we begin creating these things, what are user-defined aggregates?  They are a feature introduced in Oracle 9i that allows a developer to create his or her own functions like "SUM", "AVG", and…
This post first appeared at Oracleinaction  (http://oracleinaction.com/undo-and-redo-in-oracle/)by Anju Garg (Myself). I  will demonstrate that undo for DML’s is stored both in undo tablespace and online redo logs. Then, we will analyze the reaso…
This video shows syntax for various backup options while discussing how the different basic backup types work.  It explains how to take full backups, incremental level 0 backups, incremental level 1 backups in both differential and cumulative mode a…
This video shows how to configure and send email from and Oracle database using both UTL_SMTP and UTL_MAIL, as well as comparing UTL_SMTP to a manual SMTP conversation with a mail server.

757 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question

Need Help in Real-Time?

Connect with top rated Experts

21 Experts available now in Live!

Get 1:1 Help Now