Exchange only partially backs up

[miro]

Recently moved to TSM Server 5.4 from 5.2
I have one Exchange client.
On the old system there was no problem backing up a full on 4 Exchange Groups on a Friday and doing incrementals Mon to Thurs - it actually worked very well.
I did not upgrade the Exchange client to avoid making too many changes at once.
We did not export the old Exchange data to the new 5.4 Server, but started a clean fresh Exchange backup.
Now, on the new TSM 5.4 , the incrementals are OK and start up as per schedule.
The full on Friday starts OK, and does a full backup on 2 of the 4 Exchange Groups, but then it seems to hang and ultimately, I get a Server message that the Exchange client has timed out after 10,000 sec on the 3rd Exchange Group and it doesn't even start the full backup of the 4th Exchange Group.

Has anyone seen a similar problem?
Is there some sort of "non-comptability' between Server 5.4 and Exchange Client 5.2?

I'd like to sort this out before moving to Exchange Client 5.4. It is perplexing and very puzzling because it sort of works and then hangs.

Any assistance would be greatly appreciated by this one lone TSM admin.
Miro


Here are some of the Client logs


From dsierror.log

12/21/2007 17:52:16 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:35:57 sessSendVerb: Error sending Verb, rc: -50
12/29/2007 10:35:57 sessSendVerb: Error sending Verb, rc: -50
12/29/2007 10:35:57 cuConfirm: Received rc: -50 trying to send Confirm verb
12/29/2007 10:35:57 sessSendVerb: Error sending Verb, rc: -50
12/29/2007 10:36:39 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:36:39 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:37:21 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:37:21 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:38:03 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:38:03 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:38:46 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:38:46 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:39:28 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:39:28 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:40:10 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:40:10 sessOpen: Failure in communications open call. rc: -50
12/29/2007 10:40:52 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:40:52 sessOpen: Failure in communications open call. rc: -50

From dsmerror.log

12/29/2007 10:40:52 ANS1909E The scheduled command failed.
12/29/2007 10:40:52 ANS1512E Scheduled event 'EXCHANGE_SCHEDULE_SAT' failed. Return code = 402.
12/29/2007 10:41:34 TcpOpen: TCP/IP error connecting to server.
12/29/2007 10:41:34 sessOpen: Failure in communications open call. rc: -50
12/31/2007 18:18:18 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:18:18 ConsoleEventHandler(): Process Detached.
12/31/2007 18:18:18 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:18:18 ConsoleEventHandler(): Process Detached.
12/31/2007 18:18:18 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:18:18 ConsoleEventHandler(): Process Detached.
12/31/2007 18:18:19 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:18:19 ConsoleEventHandler(): Process Detached.
12/31/2007 18:18:19 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:18:19 ConsoleEventHandler(): Process Detached.
12/31/2007 18:18:19 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:18:19 ConsoleEventHandler(): Process Detached.
12/31/2007 18:18:21 ConsoleEventHandler(): Caught Shutdown console event .
12/31/2007 18:18:21 ConsoleEventHandler(): Cleaning up and terminating Process ...
12/31/2007 18:18:21 ConsoleEventHandler(): Caught Shutdown console event .
12/31/2007 18:18:21 ConsoleEventHandler(): Cleaning up and terminating Process ...
12/31/2007 18:18:21 ConsoleEventHandler(): Caught Shutdown console event .
12/31/2007 18:18:21 ConsoleEventHandler(): Cleaning up and terminating Process ...
12/31/2007 18:46:38 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:46:38 ConsoleEventHandler(): Process Detached.
12/31/2007 18:46:38 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:46:38 ConsoleEventHandler(): Process Detached.
12/31/2007 18:46:38 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:46:38 ConsoleEventHandler(): Process Detached.
12/31/2007 18:46:39 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:46:39 ConsoleEventHandler(): Process Detached.
12/31/2007 18:46:39 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:46:39 ConsoleEventHandler(): Process Detached.
12/31/2007 18:46:39 ConsoleEventHandler(): Caught Logoff console event .
12/31/2007 18:46:39 ConsoleEventHandler(): Process Detached.
12/31/2007 18:46:41 ConsoleEventHandler(): Caught Shutdown console event .
12/31/2007 18:46:41 ConsoleEventHandler(): Cleaning up and terminating Process ...
12/31/2007 18:46:41 ConsoleEventHandler(): Caught Shutdown console event .
12/31/2007 18:46:41 ConsoleEventHandler(): Cleaning up and terminating Process ...
12/31/2007 18:46:41 ConsoleEventHandler(): Caught Shutdown console event .
12/31/2007 18:46:41 ConsoleEventHandler(): Cleaning up and terminating Process ...
12/31/2007 21:59:34 ANS1809W Session is lost; initializing session reopen procedure.
12/31/2007 21:59:34 ANS1809W Session is lost; initializing session reopen procedure.
12/31/2007 21:59:49 ANS1810E TSM session has been reestablished.


From dsmexchdata.log

12/28/2007 19:47:46 ============== Log file pruned using log retention period of 5 day(s)
12/28/2007 19:47:46 ============== No log entries pruned
12/28/2007 19:47:46 =========================================================================
12/28/2007 19:47:46 Request : Backup
12/28/2007 19:47:46 SG List : *
12/28/2007 19:47:46 Backup Type : FULL
12/28/2007 19:47:46 Database Name :
12/28/2007 19:47:46 Buffers : 3
12/28/2007 19:47:46 Buffersize : 1024
12/28/2007 19:47:46 Exchange Server : (Local Machine)
12/28/2007 19:47:46 TSM Node Name :
12/28/2007 19:47:46 TSM Options File : dsm.opt
12/28/2007 19:47:46 Mount Wait : Yes
12/28/2007 19:47:46 Quiet : No
12/28/2007 19:47:46 -------------------------------------------------------------------------
12/29/2007 10:36:39 Backup of storage group Secondary Storage Group failed.
12/29/2007 10:36:39 ANS1017E (RC-50) Session rejected: TCP/IP connection failure
12/29/2007 10:38:46 Backup of storage group Administrative Storage Group failed.
12/29/2007 10:38:46 ANS1017E (RC-50) Session rejected: TCP/IP connection failure
12/29/2007 10:40:10 Retrying failed backups...
12/29/2007 10:40:52 Total storage groups requested for backup: 4
12/29/2007 10:40:52 Total storage groups backed up: 2
12/29/2007 10:40:52 Total storage groups expired: 0
12/29/2007 10:40:52 Total storage groups excluded: 0
12/29/2007 10:40:52 Throughput rate: 5,092.05 Kb/Sec
12/29/2007 10:40:52 Total bytes transferred: 278,294,636,720
12/29/2007 10:40:52 Elapsed processing time: 53,371.83 Secs
12/29/2007 10:40:52 ANS1017E (RC-50) Session rejected: TCP/IP connection failure
12/31/2007 21:20:27 ============== Log file pruned using log retention period of 5 day(s)
12/31/2007 21:20:27 ============== 44 out of 116 entries pruned from the top of this log
12/31/2007 21:20:27 =========================================================================
12/31/2007 21:20:27 Request : Backup
12/31/2007 21:20:27 SG List : *
12/31/2007 21:20:27 Backup Type : INCREMENTAL
12/31/2007 21:20:27 Database Name :
12/31/2007 21:20:27 Buffers : 3
12/31/2007 21:20:27 Buffersize : 1024
12/31/2007 21:20:27 Exchange Server : (Local Machine)
12/31/2007 21:20:27 TSM Node Name :
12/31/2007 21:20:27 TSM Options File : dsm.opt
12/31/2007 21:20:27 Mount Wait : Yes
12/31/2007 21:20:27 Quiet : No
12/31/2007 21:20:27 -------------------------------------------------------------------------
12/31/2007 21:26:59 Total storage groups requested for backup: 4
12/31/2007 21:26:59 Total storage groups backed up: 4
12/31/2007 21:26:59 Total storage groups expired: 0
12/31/2007 21:26:59 Total storage groups excluded: 0
12/31/2007 21:26:59 Throughput rate: 7,194.26 Kb/Sec
12/31/2007 21:26:59 Total bytes transferred: 2,857,416,172
12/31/2007 21:26:59 Elapsed processing time: 387.87 Secs
01/01/2008 22:06:08 ============== Log file pruned using log retention period of 5 day(s)
01/01/2008 22:06:08 ============== 22 out of 94 entries pruned from the top of this log

 

[sgabriel62]

You may have to extend your comm and idle timeout variables on the TSM server as well as inserting the appropriate variables at the client.
Take a look at your tcp settings - they also may need to be adjusted.
You'll also need to upgrade your Exchange client too as well - I believe there is a newer one posted supporting TSM 5.4

Hope this helps

 

[JohanW]

We backup Exchange to a 5.4.1.2 server no problem. TSM client 5.3.4.8, TDP 5.2.1.0 (if it works, don't fix it - it's a cluster too).