ADSM-L

Recovery Log behavior after 100% util reached

2002-01-10 12:51:33
Subject: Recovery Log behavior after 100% util reached
From: Denis L'Huillier <dlhuillier AT PERSHING DOT COM>
Date: Thu, 10 Jan 2002 12:45:54 -0500
Hello,

I have recently inherited an over worked, maxed out TSM server where the
recovery log maxes out
on just about a nightly basis.  I have 2 questions maybe someone can help
me with.
1.  Why does the server only crash sometimes when the log fills up.  For
example, yesterday it reached
100% but never went down.  2 days ago it reached 100% and TSM crashed.

2.  When the server didn't crash the log kind of automatically zero'd
itself after reaching 100%.
What happened to all those uncommitted changes to the database? Did I lose
data?  Shouldn't the
log remain at 100% actual used until a db backup takes place?

I have a 'q log' script in cron that runs every 10 minutes and this is the
output during that time frame:

Server date/time: 01/10/02   02:10:10  Last access: 01/10/02   02ANS8000I
Server command: 'q log'
    2,564        2,564             0           564       4,096
655,872       510,699      77.9      77.9

Server date/time: 01/10/02   03:00:04  Last access: 01/10/02   02ANS8000I
Server command: 'q log'
    2,564        2,564             0             8       4,096
655,872       653,290      99.6      99.6

Server date/time: 01/10/02   03:20:00  Last access: 01/10/02   03ANS8000I
Server command: 'q log'
    2,564        2,564             0         2,560       4,096
655,872           189       0.0     100.0

Server date/time: 01/10/02   03:10:01  Last access: 01/10/02   03ANS8000I
Server command: 'q log'
    2,564        2,564             0         2,560       4,096
655,872           189       0.0     100.0

As you can see the log reached 100% (99.6) at 3:00am and at 3:10 zero'd
out.  But no backups took place until about 4:50am
and my database backup doesn't kick in until 9:00 am.. Also we are in
normal log mode, no triggers.
Here's the act log for this time frame:

tsm: ADSMFP>q act begint=03:10 endt=04:54

Date/Time                Message
--------------------
----------------------------------------------------------
----------------------------------------------------------
01/10/02   03:10:01      ANR0402I Session 2282 started for administrator
01/10/02   03:10:01      ANR0402I Session 2282 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   03:10:01      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   03:10:01      ANR0405I Session 2282 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   03:20:00      ANR0402I Session 2283 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   03:20:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   03:20:00      ANR0405I Session 2283 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   03:21:40      ANR0406I Session 2284 started for node
INAFPUXPAS02 (SUN
                          SOLARIS) (Tcp/Ip 172.22.70.4(57097)).
01/10/02   03:21:40      ANR0403I Session 2284 ended for node INAFPUXPAS02
(SUN
                          SOLARIS).
01/10/02   03:30:00      ANR0402I Session 2285 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   03:30:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   03:30:00      ANR0405I Session 2285 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   03:40:01      ANR0402I Session 2286 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   03:40:01      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   03:40:01      ANR0405I Session 2286 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   03:50:00      ANR0402I Session 2287 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   03:50:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   03:50:00      ANR0405I Session 2287 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:00:00      ANR0402I Session 2288 started for administrator
SCRIPT_ID
01/10/02   04:00:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY
                          SESSION
01/10/02   04:00:00      ANR0405I Session 2288 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:00:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   04:00:00      ANR0405I Session 2289 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:00:01      ANR2580E Schedule DAILY_SQL in domain SQL_DOMAIN
for node
                          INAEBNTPLD01 failed.
01/10/02   04:00:02      ANR2578I Schedule DAILY_SQL in domain SQL_DOMAIN
for node
                          SQL1 has missed its scheduled start up window.
01/10/02   04:10:00      ANR0402I Session 2290 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   04:10:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   04:10:00      ANR0405I Session 2290 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:20:00      ANR0402I Session 2291 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   04:20:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   04:20:00      ANR0405I Session 2291 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:30:00      ANR0402I Session 2292 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   04:30:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   04:30:00      ANR0405I Session 2292 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:40:01      ANR0402I Session 2293 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   04:40:01      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   04:40:01      ANR0405I Session 2293 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:50:00      ANR0402I Session 2294 started for administrator
SCRIPT_ID
                          (AIX) (ShMem).
01/10/02   04:50:00      ANR2017I Administrator SCRIPT_ID issued command:
QUERY LOG
01/10/02   04:50:00      ANR0405I Session 2294 ended for administrator
SCRIPT_ID
                          (AIX).
01/10/02   04:54:16      ANR0406I Session 2295 started for node
INAFPUXPDB01 (SUN
                          SOLARIS) (Tcp/Ip 172.22.70.1(65090)).
01/10/02   04:54:28      ANE4952I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects inspected:        1
01/10/02   04:54:28      ANE4954I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects backed up:        1
01/10/02   04:54:28      ANE4958I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects updated:          0
01/10/02   04:54:28      ANE4960I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects rebound:          0
01/10/02   04:54:28      ANE4957I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects deleted:          0
01/10/02   04:54:28      ANE4970I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects expired:          0
01/10/02   04:54:28      ANE4959I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of objects failed:           0
01/10/02   04:54:28      ANE4961I (Session: 2295, Node: INAFPUXPDB01)
Total number
                          of bytes transferred:    64.61 MB
01/10/02   04:54:28      ANE4963I (Session: 2295, Node: INAFPUXPDB01)  Data
                          transfer time:                    5.84 sec
01/10/02   04:54:28      ANE4966I (Session: 2295, Node: INAFPUXPDB01)
Network data
                          transfer rate:        11,324.62 KB/sec
01/10/02   04:54:28      ANE4967I (Session: 2295, Node: INAFPUXPDB01)
Aggregate
                          data transfer rate:      5,463.51 KB/sec
01/10/02   04:54:28      ANE4968I (Session: 2295, Node: INAFPUXPDB01)
Objects
                          compressed by:                    0%
01/10/02   04:54:28      ANE4964I (Session: 2295, Node: INAFPUXPDB01)
Elapsed
                          processing time:            00:00:12

Thanks in advanced for any help!

Regards,

Denis L. L'Huiller
973-360-7739
dlhuillier AT pershing DOT com
Enterprise Storage Forms ->
http://admpwb01/misc/misc/storage_forms_main.html
<Prev in Thread] Current Thread [Next in Thread>