ADSM-L

Re: Strange q ev output

2004-07-15 14:26:40
Subject: Re: Strange q ev output
From: Andrew Raibeck <storman AT US.IBM DOT COM>
To: ADSM-L AT VM.MARIST DOT EDU
Date: Thu, 15 Jul 2004 12:26:14 -0600
OK, which situation are we speaking of? If you are hitting
MAXSCHEDSESSIONS limit, then the ANR2571W messages are appropriate (at
least from what little I know of your setup). About the QUERY EVENT
results; yes, those definitely don't look right. Some observations:

- At 00:15:01 message ANR2578W is written indicating that the node missed
its scheduled backup startup window. This should cause the scheduled start
time to roll forward to 07/14/2004 23:15.

- At 01:16:55 message ANR0482W is issued for session 383155. This session
apparently started at 23:16-ish, two hours before. Back up your activity
log review to include messages from the orignial scheduled start time of
07/13/2004 23:15.

- At 01:36:34 session 384075 starts, apparently running a backup. How this
could be, I do not know if we missed the startup window. Yet later on, we
do get a message saying that the scheduled event ran successfully. Also
note that this is the time that QUERY EVENT shows for actual start.

- At 01:37:49 admin THIRD updates the schedule for this node. To me, this
should cause the scheduled start time for this event to be 07/14/2004
01:37:49, yet subsequent QUERY EVENT shows it as 07/14/2004 23:15. Why
that is, I do not know.... maybe the schedule record is somehow locked
because a scheduled session (384075) is running? I do not have in-depth
knowledge to answer this. It would appear that you only queried the
activity log for messages containing this node name. Can you check the
entire log for any other error messages that might have been issued around
this time frame (including but not limited to ANR9999D)?

- At 02:14:01 session 384075 ends.

- At 02:14:02 message ANR2507I is issued indicating that the scheduled
backup ran successfully.

- At 02:14:02 session 384494 begins for this node. I think it is trying to
run a scheduled event, but that is just a guess.

- At 02:23:39 session 384574 begins for this node.

- At 02:55:51 session 384574 ends.

- At 02:55:52 session 384494 ends.

- At 02:55:52 message ANR2507I is issued indicating that the scheduled
backup ran successfully. This should cause QUERY EVENT to show an actual
start time of 02:14:02, but why it's not there, I do not know. Again, look
for messages around this timeframe that don't contain the node name to see
if any other error messages might exist.

Unfortunately in this informal forum, it is difficult for me to go into
greater analytical depth with this problem, but something definitely
doesn't seem right. You are on the right track in looking back at the
activity log. As I said above, I suggest you review the entire log from
07/13/2004 23:15 and make notes of the sequence of events related to this
node. Don't limit your search to just messages containing the node name,
as you might miss out on some other server error messages. Also take a
look at this node's dsmsched.log, dsmerror.log, and dsmwebcl.log files to
help piece the sequence together. There is something odd going on here,
but performing analysis like I've started above is a good step towards
better understanding what might be going on. Ultimately you might need to
open a problem with IBM technical support.

Regards,

Andy

Andy Raibeck
IBM Software Group
Tivoli Storage Manager Client Development
Internal Notes e-mail: Andrew Raibeck/Tucson/IBM@IBMUS
Internet e-mail: storman AT us.ibm DOT com

The only dumb question is the one that goes unasked.
The command line is your friend.
"Good enough" is the enemy of excellence.

"ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU> wrote on 07/15/2004
10:41:56:

> I had noticed that the maximum sessions threshold had been hit, and I
can
> see that there is a correlation there.  However, if the MAXSCHEDSESSIONS
> parameter is working as designed and limiting the number of sessions,
> wouldn't this effect essentialy be a bug?  I can't imagine that this
would
> be an intended consequence of that situation occurring.  I'm going to
raise
> the threshold for the moment and see what happens over the next couple
of
> days, but it appears to be more of a workaround than a solution.  In
> addition, we have been running on this TSM server since late January,
and
> have only been seeing the problem in our Solaris environment recently as
> described below.  Could there be some strange interrelationship between
the
> server and the V5 client code, the optionset, or the dsmcad to create
this
> situation?  Those are the things that have been changed in that
environment
> recently.
>
> Thanks for your help!
>
> Kathleen
>
>
>
>
>                       "Andrew Raibeck"
>                       <storman AT US DOT IBM.C        To: ADSM-L AT VM.MARIST 
> DOT EDU
>                       OM>                      cc:
>                       Sent by: "ADSM:          Subject:  Re: Strange q
ev output
>                       Dist Stor
>                       Manager"
>                       <[email protected]
>                       .EDU>
>
>
>                       07/15/2004 12:39
>                       PM
>                       Please respond to
>                       "ADSM: Dist Stor
>                       Manager"
>
>
>
>
>
>
> Kathleen,
>
> Have you taken a look at the ANR2571W message? That may be a key to
this.
> Do "HELP ANR2571W" from the Admin CLI for info on this message, as it
> suggests some corrective actions you can take.
>
> Regards,
>
> Andy
>
> Andy Raibeck
> IBM Software Group
> Tivoli Storage Manager Client Development
> Internal Notes e-mail: Andrew Raibeck/Tucson/IBM@IBMUS
> Internet e-mail: storman AT us.ibm DOT com
>
> The only dumb question is the one that goes unasked.
> The command line is your friend.
> "Good enough" is the enemy of excellence.
>
> "ADSM: Dist Stor Manager" <ADSM-L AT VM.MARIST DOT EDU> wrote on 07/15/2004
> 08:17:43:
>
> > Well, I'm glad you asked me to look at the activity log more
closely--it
> > appears to be having a bigger impact than I'd realized.  The activity
> log
> > shows that the backup which should have been scheduled for 23:15 last
> night
> > in fact did not run.  One point which may be helpful is that only
> recently
> > did we see Solaris clients affected by this.  Up until then, I've only
> ever
> > observed it with Windows clients.  We did recently upgrade our Solaris
> > client code, and implemented the CAD and client option sets at the
same
> > time.  We are now using these on Windows, Solaris, and Netware
> clients--and
> > we see this behavior everywhere but the Netware clients.
> >
> > Kathleen
> >
> >
> > Date/Time            Message
> > --------------------
> > ----------------------------------------------------------
> > 07/14/04   00:15:01  ANR2578W Schedule HE2UNX108.2315.SOL.ANY in
domain
> SOL
> > for
> >                       node HE2UNX108 has missed its scheduled start up
> > window.
> > 07/14/04   00:16:33  ANR0406I Session 383572 started for node
HE2UNX108
> > (SUN
> >                       SOLARIS) (Tcp/Ip he2unx108.fhlmc.com(60644)).
> > (SESSION:
> >                       383572)
> > 07/14/04   00:16:33  ANR2571W Scheduled session from node HE2UNX108
(SUN
> >                       SOLARIS) has been denied, scheduled sessions are
> not
> >                       currently available. (SESSION: 383572)
> > 07/14/04   00:16:33  ANR0403I Session 383572 ended for node HE2UNX108
> (SUN
> >                       SOLARIS). (SESSION: 383572)
> > 07/14/04   00:36:33  ANR0406I Session 383627 started for node
HE2UNX108
> > (SUN
> >                       SOLARIS) (Tcp/Ip he2unx108.fhlmc.com(60655)).
> > (SESSION:
> >                       383627)
> > 07/14/04   00:36:33  ANR2571W Scheduled session from node HE2UNX108
(SUN
> >                       SOLARIS) has been denied, scheduled sessions are
> not
> >                       currently available. (SESSION: 383627)
> > 07/14/04   00:36:33  ANR0403I Session 383627 ended for node HE2UNX108
> (SUN
> >                       SOLARIS). (SESSION: 383627)
> [snip for brevity]

<Prev in Thread] Current Thread [Next in Thread>