We had similar issues and in our environment it seems it's all tied to VSS errors. Sometimes restarting the VSS service on the client and / or hyper-visor was all that was needed. Otherwise rebooting the client always fixed it (but obviously isn't always possible). We tended to get a lot of snapshot errors which accompanied the TCP errors.
Mark Glazerman Desk: 314-889-8282 Cell: 618-520-3401 please don't print this e-mail unless you really need to -----Original Message----- From: veritas-bu-boun...@mailman.eng.auburn.edu [mailto:veritas-bu-boun...@mailman.eng.auburn.edu] On Behalf Of Denzo Sent: Wednesday, July 28, 2010 7:14 AM To: VERITAS-BU@MAILMAN.ENG.AUBURN.EDU Subject: [Veritas-bu] could not set TCP_NODELAY on socket 1724,h_errno = 10038 BELOW ARE THE CONTENTS OF ..\logs\bpbkar 11:03:26.840 AM: [3144.4560] <4> ov_log::OVInit: GENERAL Log Level: 0 11:03:26.840 AM: [3144.4560] <4> ov_log::OVInit: TCP Log Level: 0 11:03:26.841 AM: [3144.4560] <4> ov_log::OVInit: INF - the log mutex: 252 BPBKAR NetBackup Backup/Archive 6.5GA [May 1 2009] Copyright 1993 - 2007 VERITAS Software Corporation All Rights Reserved. 11:03:26.844 AM: [3144.4560] <2> date_debug: DAT - current time: 1280307806, 7/28/2010 11:03:26 AM 11:03:26.844 AM: [3144.4560] <2> date_debug: DAT - 01/01/94 UCT: 757382400, 1/1/1994 2:00:00 AM 11:03:26.844 AM: [3144.4560] <2> date_debug: DAT - 07/01/94 UCT: 773020800, 7/1/1994 2:00:00 AM 11:03:26.844 AM: [3144.4560] <2> WinMain: DAT - standard input handle = 672 11:03:26.845 AM: [3144.4560] <2> WinMain: DAT - standard output handle = 140 11:03:26.845 AM: [3144.4560] <2> WinMain: DAT - standard error handle = 468 11:03:26.852 AM: [3144.4560] <4> tar_backup::V_SetupJobData: INF - dwJobData: ffffffff 11:03:26.852 AM: [3144.4560] <4> tar_backup::V_SetupJobData: INF - dwJob: ffffffff 11:03:26.855 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - backup privileges enabled, previous = 0 11:03:26.855 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - restore privileges enabled, previous = 0 11:03:26.856 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - security privileges enabled, previous = 0 11:03:26.856 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - tcb privileges enabled, previous = 0 11:03:26.857 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - create token privileges enabled, previous = 0 11:03:26.857 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - user name: root 11:03:26.857 AM: [3144.4560] <4> dos_backup::V_PreProcessing: INF - no access token: scheduled backup 11:03:26.863 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - BEDS_Init() Enter InitFlags:0x0 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: C: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: D: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: E: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: F: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: G: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: H: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: J: 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Terminal Services 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Microsoft Windows Network 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: s4zaswsysq01 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Shadow?Copy?Components 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: System?State 11:03:26.897 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - DumpDleInfo() DLE Device Name: Active Directory Application Mode 11:03:26.903 AM: [3144.4560] <2> tar_backupt_tfi::create: TAR - Incremental backup using the archive bit 11:03:27.114 AM: [3144.4560] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received 11:03:27.307 AM: [3144.4560] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = ALL_LOCAL_DRIVES 11:03:27.307 AM: [3144.8112] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds 11:03:27.334 AM: [3144.4560] <2> tar_backup_vxbsa::add: INF - called with '/' 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: C:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: D:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: E:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: F:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: G:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: H:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: J:\ 11:03:27.335 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: Shadow Copy Components:\ 11:03:27.336 AM: [3144.4560] <4> dos_backup::V_VerifyFileSystem: INF - Added: System State:\ 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'System State:\' --> 1002002d 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for '_BACKUP_SPECIAL_OBJECTS AFTER System State:' --> 1002002d 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'D:\' --> 10020002 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'E:\' --> 10020002 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'F:\' --> 10020002 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'G:\' --> 10020002 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'H:\' --> 10020002 11:03:28.925 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'J:\' --> 10020002 11:03:30.339 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'Shadow Copy Components:\' --> 10020027 11:03:30.339 AM: [3144.4560] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'C:\' --> 10020002 11:03:31.675 AM: [3144.4560] <4> VssSnapshot::V_VssSetMetadata(): INF - Unable to locate DFSR metadata 11:03:32.405 AM: [3144.4560] <4> dos_backup::V_InitializeShadowCopy: INF - ============================================ 11:03:32.405 AM: [3144.4560] <4> dos_backup::V_InitializeShadowCopy: INF - ShadowCopy PrePost: Begin 11:03:34.310 AM: [3144.4560] <4> dos_backup::tfs_findfirst: WRN - unable to find first file: 'Shadow Copy Components:\System Service\Background Intelligent Transfer Service\' 11:03:34.415 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'C:' added to VSS Volume Set 11:03:34.419 AM: [3144.4560] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations 11:03:34.419 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\" 11:03:34.436 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume 11:03:38.283 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - VSS Volume Set snapped 11:03:38.283 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks 11:03:38.287 AM: [3144.4560] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations 11:03:38.287 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\" 11:03:38.304 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume 11:03:38.304 AM: [3144.4560] <4> dos_backup::V_InitializeShadowCopy: INF - ShadowCopy PrePost: End 11:03:38.304 AM: [3144.4560] <4> dos_backup::V_InitializeShadowCopy: INF - ============================================ 11:03:38.305 AM: [3144.4560] <4> VssSnapshot::V_VssSetMetadata(): INF - Unable to locate DFSR metadata 11:03:49.491 AM: [3144.4560] <4> dos_backup::tfs_scanstart: INF - Backup Special Objects request AFTER System State: 11:03:51.271 AM: [3144.4560] <4> dos_backup::tfs_findfirst: WRN - unable to find first file: 'System State:\' 11:03:51.286 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'C:' added to VSS Volume Set 11:03:51.290 AM: [3144.4560] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations 11:03:51.290 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\" 11:03:51.308 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume 11:03:51.313 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - Drive 'c:' added to VSS Volume Set 11:03:51.315 AM: [3144.4560] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations 11:03:51.315 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "c:\" 11:03:51.333 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume 11:03:55.799 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - VSS Volume Set snapped 11:03:55.799 AM: [3144.4560] <4> VssSnapshot::V_VssVolumeSnapshot(): INF - About to commence post-snap unbounded association checks 11:03:55.817 AM: [3144.4560] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations 11:03:55.817 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "C:\" 11:03:55.836 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume 11:03:55.840 AM: [3144.4560] <4> SnapshotAssociation::SnapshotAssociation: INF - VSS_MAXIMUM_STORAGE_SIZE is unavailable or the wrong type, staying with the default action of limiting unbounded associations 11:03:55.840 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - checking association status for drive "c:\" 11:03:55.859 AM: [3144.4560] <4> SnapshotAssociation::AdjustUnboundedAssocations: INF - QueryDiffAreasForVolume returned failure status; no Diff areas for this volume 11:03:55.865 AM: [3144.4560] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp' 11:03:55.866 AM: [3144.4560] <16> dtcp_write: TCP - failure: send socket (468) (TCP 10054: Connection reset by peer) 11:03:55.866 AM: [3144.4560] <16> dtcp_write: TCP - failure: attempted to send 21 bytes 11:03:57.822 AM: [3144.4560] <2> ov_log::V_GlobalLogEx: INF - beds_ss_access::V_OpenForRead(): FS_OpenObj() Successful. 11:03:57.855 AM: [3144.4560] <32> TransporterRemote::write[2](): FTL - SocketWriteException: send() call failed, could not write data to the socket, possible broken connection. 11:03:57.855 AM: [3144.4560] <16> NBUException::traceException(): ( An Exception of type [Symantec::NetBackup::Ncf::OperationFailedException] was thrown. Details about the exception follow...: Error code = (-1008). Src file = (D:\654\src\cl\clientpc\util\tar_tfi.cpp). Src Line = (275). Description = (%s getBuffer operation failed). Operation type=(). ) 11:03:57.856 AM: [3144.4560] <16> NBUException::traceException(): ( An Exception of type [Symantec::NetBackup::Ncf::SocketWriteException] was thrown. Details about the exception follow...: Error code = (-1027). Src file = (TransporterRemote.cpp). Src Line = (310). Description = (send() call failed, could not write data to the socket, possible broken connection). Local IP=(). Remote IP=(). Remote Port No.=(0). No. of bytes to write=(32768) while No. of bytes written=(0). ) 11:03:57.856 AM: [3144.4560] <2> tar_base::V_vTarMsgW: FTL - socket write failed 11:03:57.856 AM: [3144.4560] <16> dtcp_write: TCP - failure: send socket (468) (TCP 10054: Connection reset by peer) 11:03:57.856 AM: [3144.4560] <16> dtcp_write: TCP - failure: attempted to send 26 bytes 11:03:57.856 AM: [3144.4560] <4> tar_backup::backup_done_state: INF - number of file directives not found: 0 11:03:57.856 AM: [3144.4560] <4> tar_backup::backup_done_state: INF - number of file directives found: 4 11:03:57.856 AM: [3144.8112] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0) 11:03:57.857 AM: [3144.4560] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0) 11:03:57.857 AM: [3144.4560] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 24: socket write failed 11:03:57.857 AM: [3144.4560] <16> dtcp_write: TCP - failure: send socket (468) (TCP 10054: Connection reset by peer) 11:03:57.857 AM: [3144.4560] <16> dtcp_write: TCP - failure: attempted to send 42 bytes 11:03:57.857 AM: [3144.4560] <4> tar_backup::backup_done_state: INF - Not waiting for server status 11:03:57.857 AM: [3144.4560] <4> dos_backup::tfs_reset: INF - Snapshot deletion start 11:03:58.659 AM: [3144.4560] <4> OVStopCmd: INF - EXIT - status = 0 11:03:58.659 AM: [3144.4560] <2> tar_base::V_Close: closing... 11:03:58.659 AM: [3144.4560] <4> dos_backup::tfs_reset: INF - Snapshot deletion start 11:03:59.560 AM: [3144.4560] <2> ov_log::V_GlobalLog: INF - BEDS_Term(): enter - InitFlags:0x00000001 11:03:59.583 AM: [3144.4560] <16> dtcp_read: TCP - failure: recv socket (672) (TCP 10053: Software caused connection abort) 11:03:59.584 AM: [3144.4560] <4> OVShutdown: INF - Finished process 11:03:59.587 AM: [3144.4560] <4> WinMain: INF - Exiting C:\Program Files\Veritas\NetBackup\bin\bpbkar32.exe 11:04:01.593 AM: [3144.4560] <4> ov_log::OVClose: INF - Closing log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\072810.LOG 11:03:26.840 AM: [3144.4560] <4> ov_log::OVInit: INF - Starting log file: C:\Program Files\Veritas\NetBackup\logs\BPBKAR\072810.LOG +---------------------------------------------------------------------- |This was sent by mulau...@gmail.com via Backup Central. |Forward SPAM to ab...@backupcentral.com. +---------------------------------------------------------------------- _______________________________________________ Veritas-bu maillist - Veritas-bu@mailman.eng.auburn.edu http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu _______________________________________________ Veritas-bu maillist - Veritas-bu@mailman.eng.auburn.edu http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu
