You already have the answer - log mode is normal. In this mode log is used
only to rollback a transaction. On commit the log is cleaned. So when there
is no activity the log must be 0% (or at least very close).
The drawback is that any transaction after last DBB is lost in case of
major failure. The reason for no crash on 100% utilisation might be one
transaction committing while second (and others) is held waiting for free
log space. After commit held transaction(s) continues. And possibly the
crash happens when there is very-very long transaction filling the log
alone or deadlock.
I do not know is there long transaction limit (and rollback) or deadlock
resolving methods in TSM DB as we have in RDBMSes. The only people can
answer to this are server developers.
Zlatko Krastev
IT Consultant
Denis L'Huillier <dlhuillier AT PERSHING DOT COM>@VM.MARIST.EDU> on 10.01.2002
19:45:54
Please respond to "ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU>
Sent by: "ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU>
To: ADSM-L AT VM.MARIST DOT EDU
cc:
Subject: Recovery Log behavior after 100% util reached
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
|
