ADSM-L

Novel Client Problem

2001-10-09 12:55:25
Subject: Novel Client Problem
From: Gerald Wichmann <gwichmann AT SANSIA DOT COM>
Date: Tue, 9 Oct 2001 09:53:25 -0700
Novell 5.1 client running TSM 4.1.3 BA Client
AIX 4.3.3 server running TSM 4.1.2 Server

This client has backed up successfully several days before in the past,
but yesterday it failed. There doesn't seem to be any specific cause for
the failure that I can see. I've included output below from both client
log files as well as the server activity log. Appreciate it if anyone
has any input/suggestions.

Someone mentioned on the list that some newer clients are behaving
differently now. When a file is failed the scheduled event comes back as
failed even though the backup was successful. Initially this seemed like
it might apply here but then I notice only 1 object was inspected so
that doesn't seem to be the case. Plus the client code is older here
(4.1.3).

What would you do next?

>From dsmsched.log:

10/08/2001 00:27:28 --- SCHEDULEREC OBJECT BEGIN NBBJ 10/08/2001
00:00:00
10/08/2001 00:27:28 Incremental backup of volume 'SEA-NWFS-G\SERVER
SPECIFIC INFO'
10/08/2001 00:27:28 Incremental backup of volume 'SEA-NWFS-G\SYS:'
10/08/2001 00:27:28 ANS1076E *** Directory path not found ***
10/08/2001 00:27:28 Incremental backup of volume 'SEA-NWFS-G\MAC_DATA:'
10/08/2001 00:27:28 ANS1076E *** Directory path not found ***
10/08/2001 00:27:28 Incremental backup of volume 'SEA-NWFS-G\QUEUES:'
10/08/2001 00:27:28 ANS1076E *** Directory path not found ***
10/08/2001 00:27:33 Normal File-->         1,048,576 Server Specific
Info/Server Specific Info [Sent]
10/08/2001 00:27:33 Successful incremental backup of 'Server Specific
Info/Server Specific Info'
10/08/2001 00:27:33 --- SCHEDULEREC STATUS BEGIN
10/08/2001 00:27:33 Total number of objects inspected:        1
10/08/2001 00:27:33 Total number of objects backed up:        1
10/08/2001 00:27:33 Total number of objects updated:          0
10/08/2001 00:27:33 Total number of objects rebound:          0
10/08/2001 00:27:33 Total number of objects deleted:          0
10/08/2001 00:27:33 Total number of objects expired:          0
10/08/2001 00:27:33 Total number of objects failed:           0
10/08/2001 00:27:33 Total number of bytes transferred:   743.80 KB
10/08/2001 00:27:33 Data transfer time:                    0.16 sec
10/08/2001 00:27:33 Network data transfer rate:        4,648.78 KB/sec
10/08/2001 00:27:33 Aggregate data transfer rate:        144.14 KB/sec
10/08/2001 00:27:33 Objects compressed by:                    0%
10/08/2001 00:27:33 Elapsed processing time:           00:00:05
10/08/2001 00:27:33 --- SCHEDULEREC STATUS END
10/08/2001 00:27:33 --- SCHEDULEREC OBJECT END NBBJ 10/08/2001 00:00:00
10/08/2001 00:27:33 ANS1512E Scheduled event 'NBBJ' failed.  Return code
= 4.
10/08/2001 00:27:33 Sending results for scheduled event 'NBBJ'.
10/08/2001 00:27:33 Results sent to server for scheduled event 'NBBJ'.

10/08/2001 00:27:33 ANS1483I Schedule log pruning started.
10/08/2001 00:27:35 Schedule Log Prune: 3608 lines processed.  286 lines
pruned.
10/08/2001 00:27:35 ANS1484I Schedule log pruning finished successfully.
10/08/2001 00:27:35 Querying server for next scheduled event.
10/08/2001 00:27:35 Node Name: SEA-NWFS-G

>From dsmc help:


------------------------------------------------------------------------
ANS1512E Scheduled event 'event' failed. Return code = value.
ANS1512E Scheduled event 'event' failed. Return code = value.



Explanation: The scheduled event did not complete successfully.

System Action: Scheduled event failed.

User Response: Ensure that your environment is set up correctly. If the

problem continues, see your system administrator to correct the problem.




------------------------------------------------------------------------
>From TSM Server activity log:
>From TSM Server activity log:

tsm: TSM>q act begind=today-1 begint=00:00 search=nwfs-g

Date/Time                Message

--------------------
----------------------------------------------------------
----------------------------------------------------------
10/08/01   00:18:46      ANR0406I Session 874 started for node
10/08/01   00:18:46      ANR0406I Session 874 started for node
SEA-NWFS-G (NetWare)
                          (Tcp/Ip 10.4.0.7(1458)).

10/08/01   00:18:46      ANR0403I Session 874 ended for node SEA-NWFS-G
(NetWare).
10/08/01   00:23:48      ANR0406I Session 879 started for node
SEA-NWFS-G (NetWare)
                          (Tcp/Ip 10.4.0.7(1459)).

10/08/01   00:23:50      ANR0406I Session 880 started for node
SEA-NWFS-G (NetWare)
                          (Tcp/Ip 10.4.0.7(1462)).

10/08/01   00:23:53      ANR0403I Session 880 ended for node SEA-NWFS-G
(NetWare).
10/08/01   00:23:53      ANE4952I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects inspected:        1

10/08/01   00:23:53      ANE4954I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects backed up:        1

10/08/01   00:23:53      ANE4958I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects updated:          0

10/08/01   00:23:53      ANE4960I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects rebound:          0

10/08/01   00:23:53      ANE4957I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects deleted:          0

10/08/01   00:23:53      ANE4970I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects expired:          0

10/08/01   00:23:53      ANE4959I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          objects failed:           0

10/08/01   00:23:53      ANE4961I (Session: 879, Node: SEA-NWFS-G)
Total number of
                          bytes transferred:   743.80 KB

10/08/01   00:23:53      ANE4963I (Session: 879, Node: SEA-NWFS-G)  Data
transfer
                          time:                    0.16 sec

10/08/01   00:23:53      ANE4966I (Session: 879, Node: SEA-NWFS-G)
Network data
                          transfer rate:        4,648.78 KB/sec

10/08/01   00:23:53      ANE4967I (Session: 879, Node: SEA-NWFS-G)
Aggregate data
                          transfer rate:        144.14 KB/sec

10/08/01   00:23:53      ANE4968I (Session: 879, Node: SEA-NWFS-G)
Objects
                          compressed by:                    0%

10/08/01   00:23:53      ANE4964I (Session: 879, Node: SEA-NWFS-G)
Elapsed
                          processing time:            00:00:05

10/08/01   00:23:53      ANR2579E Schedule NBBJ in domain NBBJ for node
SEA-NWFS-G
                          failed (return code 4).

10/08/01   00:23:53      ANR0403I Session 879 ended for node SEA-NWFS-G
(NetWare).
10/08/01   00:23:55      ANR0406I Session 881 started for node
SEA-NWFS-G (NetWare)
                          (Tcp/Ip 10.4.0.7(1465)).

10/08/01   00:23:55      ANR0403I Session 881 ended for node SEA-NWFS-G
(NetWare).
10/08/01   04:23:55      ANR0406I Session 897 started for node
SEA-NWFS-G (NetWare)
                          (Tcp/Ip 10.4.0.7(1466)).

10/08/01   04:23:55      ANR0403I Session 897 ended for node SEA-NWFS-G
(NetWare).
10/08/01   05:00:38      ANR4391I Expiration processing node SEA-NWFS-G,
filespace

>From dsmadmc Help:

tsm: TSM>help anr2579e
------------------------------------------------------------------------
-------
-------
ANR2579E Schedule schedule name in domain domain name for node node name
ANR2579E Schedule schedule name in domain domain name for node node name
failed (return code return code).

Explanation: This message is displayed when a client reports failure in
executing a scheduled action. The return code reported by the client is
displayed.

System Action: Server operation continues.

User Response: Examine the node's schedule log to determine the cause
for
the failure.


tsm: TSM>

We're getting nowhere.. last thing to check, dsmerror.log:

10/08/2001 00:27:28 (TSA500.NLM 5.3 259) This program cannot allocate a
directory handle.
10/08/2001 00:27:28 ANS1076E *** Directory path not found ***
10/08/2001 00:27:28 (TSA500.NLM 5.3 259) This program cannot allocate a
directory handle.
10/08/2001 00:27:28 ANS1076E *** Directory path not found ***
10/08/2001 00:27:28 (TSA500.NLM 5.3 259) This program cannot allocate a
directory handle.
10/08/2001 00:27:28 ANS1076E *** Directory path not found ***
10/08/2001 00:27:33 ANS1512E Scheduled event 'NBBJ' failed.  Return code
= 4.

Ahh..  lets check help on those:


------------------------------------------------------------------------
ANS1076E *** Directory path not found ***
ANS1076E *** Directory path not found ***



Explanation: You specified an incorrect directory path.

System Action: Processing stopped.

User Response: Correct the syntax specified and retry the operation.




------------------------------------------------------------------------
Unfortunately the timestamp on those errors is 00:27:28. The scheduler
Unfortunately the timestamp on those errors is 00:27:28. The scheduler
successfully backed up a file shortly thereafter so those errors were
not the determining factor that caused the backup to fail.

Bottom line is we don't know why the backup failed. We know the problem
is client-side.

Thanks much,


Gerald Wichmann
System Engineer
StorageLink
408-844-8893 (v)
408-844-9801 (f)
<Prev in Thread] Current Thread [Next in Thread>