Veritas-bu
[Top] [All Lists]
<prev [Date] next>
[Advanced]
 <prev [Thread] next>

Re: [Veritas-bu] could not set TCP_NODELAY on socket 1724, h_errno = 10038

2010-07-28 15:20:58
Subject: Re: [Veritas-bu] could not set TCP_NODELAY on socket 1724, h_errno = 10038
From: "Mark Glazerman" <Mark.Glazerman AT spartech DOT com>
To: <VERITAS-BU AT MAILMAN.ENG.AUBURN DOT EDU>
Date: Wed, 28 Jul 2010 14:20:53 -0500 
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-bounces AT mailman.eng.auburn DOT edu 
[mailto:veritas-bu-bounces AT mailman.eng.auburn DOT edu] On Behalf Of Denzo
Sent: Wednesday, July 28, 2010 7:14 AM
To: VERITAS-BU AT MAILMAN.ENG.AUBURN DOT 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 mulauzid AT gmail DOT com via Backup Central.
|Forward SPAM to abuse AT backupcentral DOT com.
+----------------------------------------------------------------------


_______________________________________________
Veritas-bu maillist  -  Veritas-bu AT mailman.eng.auburn DOT edu
http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu
_______________________________________________
Veritas-bu maillist  -  Veritas-bu AT mailman.eng.auburn DOT edu
http://mailman.eng.auburn.edu/mailman/listinfo/veritas-bu
[More with this subject...]
<Prev in Thread] Current Thread [Next in Thread>
Previous by Date:  Re: [Veritas-bu] bperror differences in 6.5.x and 7.0, Scott Jacobson
Next by Date:  Re: [Veritas-bu] could not set TCP_NODELAY on socket 1724, h_errno = 10038, Daniel Otto
Previous by Thread:  [Veritas-bu] could not set TCP_NODELAY on socket 1724, h_errno = 10038, Denzo
Next by Thread:  Re: [Veritas-bu] could not set TCP_NODELAY on socket 1724, h_errno = 10038, Daniel Otto
Indexes:  [Date] [Thread] [Top] [All Lists]