ADSM-L

Re: Strange Novell Backup Behavior

2002-05-01 15:55:42
Subject: Re: Strange Novell Backup Behavior
From: Zlatko Krastev <acit AT ATTGLOBAL DOT NET>
Date: Wed, 1 May 2002 22:55:14 +0300
What is the value of IDLETimeout option in dsmserv.opt? If it is not
defined it would default to 10 minutes (600 seconds). Try to increase it
to 120-720 (2-6 hours) to prevent control session be closed by the server.
You are having many files and it may take long time while TSM is skipping
not changed ones.

Zlatko Krastev
IT Consultant




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:        Strange Novell Backup Behavior

We have a Novell 4.11 client running TSM 3.7 client..TSM server running
4.1.5.

The Novell server houses part of our GroupWise email system.....a session
starts but the server activity log reports ANR0481W Session xxx for node
XXX (Netware) terminated - client did not respond within 600
seconds...session then starts again and so on and so on...the next morning
the session is still open, there is a <?> in the event log and the backups
may or may not have run successfully.

In the client dsmerror.log we have:

04/29/2002 02:04:36 ANS1006E TCP/IP write error on socket = 8, errno = 32,
reason : unknown error
04/29/2002 02:04:37 sessRecvVerb: Error -50 from call to 'readRtn'.
04/29/2002 02:04:37 ANS1006E TCP/IP write error on socket = 8, errno = 32,
reason : unknown error
04/29/2002 02:04:37 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 02:04:38 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 02:04:53 ANS1810E TSM session has been reestablished.
04/29/2002 06:56:43 ANS1005E TCP/IP read error on socket = 13, errno = 54,
reason : unknown error
04/29/2002 06:56:43 sessRecvVerb: Error -50 from call to 'readRtn'.
04/29/2002 06:56:43 cuConfirm: Received rc: -50 trying to receive
ConfirmResp verb
04/29/2002 06:56:44 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 06:56:44 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 06:56:59 cuSignOnResp: Server rejected session; result code: 69
04/29/2002 06:56:59 sessOpen: Error 69 receiving SignOnResp verb from
server
04/29/2002 06:56:59 ANS1811S TSM session could not be reestablished.
04/29/2002 06:57:03 ANS1006E TCP/IP write error on socket = 8, errno = 32,
reason : unknown error
04/29/2002 06:57:03 sessRecvVerb: Error -50 from call to 'readRtn'.
04/29/2002 06:57:03 ANS1006E TCP/IP write error on socket = 8, errno = 32,
reason : unknown error
04/29/2002 06:57:03 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 06:57:06 ANS1369W Session Rejected: The session was canceled by
the server administrator.

04/29/2002 06:57:06 ANS1512E Scheduled event 'GWISE_SCH' failed.  Return
code = 4.

Schedlog.txt shows:

04/29/2002 02:04:38 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 02:04:53 ANS4900W Schedule 'GWISE_SCH' has opened a new session
with the server.... successful
04/29/2002 06:56:44 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 06:57:00 ... failed
04/29/2002 06:57:03 ANS1809E Session is lost; initializing session reopen
procedure.
04/29/2002 06:57:06 --- SCHEDULEREC STATUS BEGIN
04/29/2002 06:57:06 Session established with server ADSM: AIX-RS/6000
04/29/2002 06:57:06   Server Version 4, Release 1, Level 5.0
04/29/2002 06:57:06   Data compression forced off by the server
04/29/2002 06:57:06   Server date/time: 04/29/2002 06:47:46  Last access:
04/29/2002 06:47:40
04/29/2002 06:57:06 Total number of objects inspected:  345,818
04/29/2002 06:57:06 Total number of objects backed up:  191,783
04/29/2002 06:57:06 Total number of objects updated:          0
04/29/2002 06:57:06 Total number of objects rebound:          0
04/29/2002 06:57:06 Total number of objects deleted:          0
04/29/2002 06:57:06 Total number of objects expired:        738
04/29/2002 06:57:06 Total number of objects failed:           2
04/29/2002 06:57:06 Total number of bytes transferred:     4.79 GB
04/29/2002 06:57:06 Data transfer time:                  424.14 sec
04/29/2002 06:57:06 Network data transfer rate:        11,858.64 KB/sec
04/29/2002 06:57:06 Aggregate data transfer rate:         45.38 KB/sec
04/29/2002 06:57:06 Objects compressed by:                    0%
04/29/2002 06:57:06 Elapsed processing time:           30:47:00
04/29/2002 06:57:06 --- SCHEDULEREC STATUS END
04/29/2002 06:57:06 ANS1369W Session Rejected: The session was canceled by
the server administrator.

04/29/2002 06:57:06 --- SCHEDULEREC OBJECT END GWISE_SCH 04/28/2002
00:00:00
04/29/2002 06:57:06 ANS1512E Scheduled event 'GWISE_SCH' failed.  Return
code = 4.
04/29/2002 06:57:07 Sending results for scheduled event 'GWISE_SCH'.
04/29/2002 06:57:07 Node Name: FS10
04/29/2002 06:57:07 Session established with server ADSM: AIX-RS/6000
04/29/2002 06:57:07   Server Version 4, Release 1, Level 5.0
04/29/2002 06:57:07   Data compression forced off by the server
04/29/2002 06:57:07   Server date/time: 04/29/2002 06:47:47  Last access:
04/29/2002 06:47:46

04/29/2002 06:57:07 Results sent to server for scheduled event
'GWISE_SCH'.

04/29/2002 06:57:07 ANS1483I Schedule log pruning started.
04/29/2002 06:57:07 Schedule Log Prune: 826 lines processed.  216 lines
pruned.
04/29/2002 06:57:07 ANS1484I Schedule log pruning finished successfully.


On this particular day the backup ran but finished way outside of the
start window of 00:00 to 03:00 and we finally canceled the
session...sometimes the backup never completes and we have the <?> in the
event log as mentioned above.

Yesterday evening we tried a manual backup and the log shows:

04/30/2002 17:18:10 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:10 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:11 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:11 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:12 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:12 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:13 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:13 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:14 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:14 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:15 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:15 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:15 ANS1006E TCP/IP write error on socket = 4294967295,
errno = 4, reason : Bad file number
04/30/2002 17:18:15 sessSendVerb: Error sending Verb, rc: -50
04/30/2002 17:18:15 cuPing: Out of sequence verb: verb: 61
04/30/2002 17:18:15 sessOpen: Session state transition error, sessState:
sSignedOn.
04/30/2002 17:18:15 sessOpen: Transitioning: sSignedOn state ===>
sTRANSERR state

any ideas?

Thanks so much!

Kelli Jones
Chesterfield County Information Systems Technology
jonesk AT co.chesterfield.va DOT us
phone: 804-748-1951
fax: 804-748-1571
<Prev in Thread] Current Thread [Next in Thread>