Veritas-bu

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

2010-07-28 15:41:53
Subject: Re: [Veritas-bu] could not set TCP_NODELAY on socket 1724, h_errno = 10038
From: "Daniel Otto" <dan_otto AT symantec DOT com>
To: <VERITAS-BU AT MAILMAN.ENG.AUBURN DOT EDU>
Date: Wed, 28 Jul 2010 12:41:36 -0700
Increase the storage size for VSS to unlimited- 

After upgrading to NetBackup 6.5.4, adjustments may be made to Windows
VSS settings that lead to individual snapshots being deleted
unexpectedly on a Windows client. This affects snapshots that are taken
outside of NetBackup manually or with a third party application.

http://support.veritas.com/docs/327791

I have also seen problems with disabling nagle on the TCP socket fixed
by setting up the server to use TCP scaling- 

What is TCP Windows Scaling- 

tcp_window_scaling
This  feature  allows the use of a large window (> 64K) on a TCP
connection, should the other end support it.  Normally,  the  16 bit
window length field in the TCP header limits the window size
to less than 64K bytes.  If larger windows are desired, 
applications can increase the size of their socket buffers and the 
window scaling option will be employed.  If tcp_window_scaling  is
disabled,  TCP will not negotiate the use of window scaling with
the other end during connection setup.
Enable RFC1323 TCP window scaling. On most Platforms it is  enabled  by
default.

For all platforms, rfc1323 must be set to have window sizes larger than
64 KB-1:

Windows - Windows(r) XP and 2003: Add or modify, with regedit, the
following registry name/value pair under
[HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Tcpip\Parameters]
Tcp1323Opts, REG_DWORD, 1 
(A 3 adds both scaling with timestamps) 
Attention: Before modifying the registry name and value pair, you should
back up the entire registry.


Solaris - ndd /dev/tcp tcp_wscale_always #(should be 1)

Linux- /proc/sys/net/ipv4/tcp_window_scaling
And modify the value from "0" to a "1" and save the file. 

HP-UX 11 RFC 1323 support is enabled automatically in HP-UX 11. If an
application requests a window/socket buffer
Enabling High Performance Data Transfers
http://www.psc.edu/networking/perf_tune.html
10 of 19 01/07/2004 11:11 AM
size greater than 64 KB, window scaling and timestamps will be used
automatically.
FREE_BSD Check 'tcp_extensions="YES"' in /etc/rc.conf and ensure it's
enabled via the sysctl variable: net.inet.tcp.rfc1323

AIX: Use no -o rfc1323=1

-----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

<Prev in Thread] Current Thread [Next in Thread>