cancel
Showing results for 
Search instead for 
Did you mean: 

could not set TCP_NODELAY on socket 1724, h_errno = 10038

Denzo
Level 3
Certified
I have a Microsoft server 2008 client.  SAN storage is presented to the client.  I added the client to our existing Windows OS backup policy which backs up ALL_LOCAL_DRIVES.  All other clients backup up successfully through the policy.  The  Microsoft server 2008 client with SAN LUN's and SQL databases gives errors  with a netbackup error code of 42.  Below is the information from the failed job. 
 
7/28/2010 7:36:07 AM - connecting
7/28/2010 7:36:08 AM - connected; connect time: 00:00:01
7/28/2010 7:36:11 AM - Warning bptm(pid=3552) could not set TCP_NODELAY on socket 1724, h_errno = 10038  
7/28/2010 7:36:11 AM - Warning bptm(pid=6892) could not set non-blocking on socket 1724, An operation was attempted on something that is not a socket.
7/28/2010 7:36:11 AM - Error bptm(pid=6892) socket operation failed - 10038 (at child.c.1294)     
7/28/2010 7:36:11 AM - Error bptm(pid=6892) unable to perform read from client socket, connection may have been broken
7/28/2010 7:36:11 AM - begin writing
7/28/2010 7:36:17 AM - end writing; write time: 00:00:06
network read failed(42)
 
 
I have a Windows 2003 Master/Media Server running NBU 6.5.4.  We are backing up to a Data Domain DD630 disk based storage unit.
 
If I restart this client backups go through, but after a week or so the problem comes back until another reboot. Is there a permanent solution to this coz we can't keep restarting the client. Please assist.
1 ACCEPTED SOLUTION

Accepted Solutions

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Have a look at this TechNote:
http://seer.entsupport.symantec.com/docs/355977.htm
Backup Job exits with Status 42 in Activity Monitor
...

13:52:29.445 [5160.4100] <8> fill_buffer: could not set non-blocking on socket 1688, An operation was attempted on something that is not a socket.
....
Resolution:
In this instance, the problem was isolated to this single machine making the point of failure isolated to the problematic new host.

If the problem is due to an unidentified corruption / misconfiguration in the new media server's TCP Stack and Winsock environment (as was the case in this example), executing these two commands, followed by a reboot will resolve the problem:

netsh int ip reset resetlog.txt   Microsoft Reference:  http://support.microsoft.com/kb/299357
netsh winsock reset catalog    Microsoft Reference:  http://technet.microsoft.com/en-us/library/cc759700(WS.10).aspx

NOTE: The above two commands will reset the Windows TCP Stack as well as the Windows Winsock environment back to the default values.  This means that if the host is configured with a static IP Address and other customized TCP settings, they will be lost and will need to be re-entered after the reboot.  The default TCP setting is to use DHCP and the host will be using DHCP upon booting up.

NOTE: Because of the nature of the two commands, it is not recommended to execute them while connected remotely.  Hands-on-keyboard is recommended.

View solution in original post

4 REPLIES 4

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Have a look at this TechNote:
http://seer.entsupport.symantec.com/docs/355977.htm
Backup Job exits with Status 42 in Activity Monitor
...

13:52:29.445 [5160.4100] <8> fill_buffer: could not set non-blocking on socket 1688, An operation was attempted on something that is not a socket.
....
Resolution:
In this instance, the problem was isolated to this single machine making the point of failure isolated to the problematic new host.

If the problem is due to an unidentified corruption / misconfiguration in the new media server's TCP Stack and Winsock environment (as was the case in this example), executing these two commands, followed by a reboot will resolve the problem:

netsh int ip reset resetlog.txt   Microsoft Reference:  http://support.microsoft.com/kb/299357
netsh winsock reset catalog    Microsoft Reference:  http://technet.microsoft.com/en-us/library/cc759700(WS.10).aspx

NOTE: The above two commands will reset the Windows TCP Stack as well as the Windows Winsock environment back to the default values.  This means that if the host is configured with a static IP Address and other customized TCP settings, they will be lost and will need to be re-entered after the reboot.  The default TCP setting is to use DHCP and the host will be using DHCP upon booting up.

NOTE: Because of the nature of the two commands, it is not recommended to execute them while connected remotely.  Hands-on-keyboard is recommended.

Denzo
Level 3
Certified

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

Denzo
Level 3
Certified
Still no joy. Anybody with a solution to my problem?

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

"Still no joy" - after trying what exactly?