Network time out 41

[rookie11]

Hi Folks

I have client server solaris 9 whose backup since past few days is failing with netwrok time out 41. i hav increased client time out setting to 3600.below is bpbkar logs :

21:18:22.273 [14363] <2> logparams: bpbkar32 -r 3628800 -ru root -dt 0 -to 0 -clnt clientbox.com -class policyname -sched Full -st FULL -bpstart_to 300 -bpend_to 300 -read_to 500 -stream_count 8 -stream_number 6 -jobgrpid 13120 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -fso -b clientbox.com_1336937647 -kl 35 -use_ofb 

21:18:22.282 [14363] <4> bpbkar: INF - Setting network send buffer size to 32032 bytes

21:18:22.282 [14363] <4> bpbkar: INF - setenv KEYWORD=NONE

21:18:22.282 [14363] <4> bpbkar: INF - setenv STREAM_PID=14363

21:18:22.282 [14363] <4> bpbkar: INF - setenv STREAM_NUMBER=6

21:18:22.282 [14363] <4> bpbkar: INF - setenv STREAM_COUNT=8

21:18:22.282 [14363] <4> bpbkar: INF - setenv STREAMS=0

21:18:22.282 [14363] <4> bpbkar: INF - setenv BPSTART_TIMEOUT=300

21:18:22.282 [14363] <4> bpbkar: INF - setenv BPEND_TIMEOUT=300

21:18:22.282 [14363] <4> bpbkar: INF - setenv RESTARTED=1

21:18:22.282 [14363] <4> bpbkar: INF - setenv BACKUPID=clientbox.com_1336937647

21:18:22.282 [14363] <4> bpbkar: INF - setenv UNIXBACKUPTIME=1336937647

21:18:22.282 [14363] <4> bpbkar: INF - setenv BACKUPTIME=Sun May 13 15:34:07 2012

21:18:22.282 [14363] <4> bpbkar: INF - Inform when done

21:18:22.282 [14363] <4> bpbkar: INF - Echo keepalives

21:18:22.284 [14363] <4> bpbkar: INF - BACKUP START

21:18:22.284 [14363] <4> bpbkar: INF - Estimate:-1 -1

21:18:22.301 [14364] <4> bpbkar main: real locales <C>

21:18:22.301 [14364] <4> bpbkar main: standardized locales - lc_messages <C> lc_ctype <C> lc_time <C> lc_collate <C> lc_numeric <C>

21:18:22.302 [14364] <2> logparams: bpbkar32 -r 3628800 -ru root -dt 0 -to 0 -clnt clientbox.com -class policyname -sched Full -st FULL -bpstart_to 300 -bpend_to 300 -read_to 500 -stream_count 8 -stream_number 7 -jobgrpid 13120 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -fso -b clientbox.com_1336938236 -kl 35 -use_ofb 

21:18:22.310 [14364] <4> bpbkar: INF - Setting network send buffer size to 32032 bytes

21:18:22.311 [14364] <4> bpbkar: INF - setenv KEYWORD=NONE

21:18:22.311 [14364] <4> bpbkar: INF - setenv STREAM_PID=14364

21:18:22.311 [14364] <4> bpbkar: INF - setenv STREAM_NUMBER=7

21:18:22.311 [14364] <4> bpbkar: INF - setenv STREAM_COUNT=8

21:18:22.311 [14364] <4> bpbkar: INF - setenv STREAMS=0

21:18:22.311 [14364] <4> bpbkar: INF - setenv BPSTART_TIMEOUT=300

21:18:22.311 [14364] <4> bpbkar: INF - setenv BPEND_TIMEOUT=300

21:18:22.311 [14364] <4> bpbkar: INF - setenv RESTARTED=1

21:18:22.311 [14364] <4> bpbkar: INF - setenv BACKUPID=clientbox.com_1336938236

21:18:22.311 [14364] <4> bpbkar: INF - setenv UNIXBACKUPTIME=1336938236

21:18:22.311 [14364] <4> bpbkar: INF - setenv BACKUPTIME=Sun May 13 15:43:56 2012

21:18:22.311 [14364] <4> bpbkar: INF - Inform when done

21:18:22.311 [14364] <4> bpbkar: INF - Echo keepalives

21:18:22.312 [14364] <4> bpbkar: INF - BACKUP START

21:18:22.312 [14364] <4> bpbkar: INF - Estimate:-1 -1

21:18:22.368 [14363] <2> bpbkar add_to_filelist: starting sizeof(filelistrec) <68>

21:18:22.369 [14363] <4> bpbkar: INF - Throttle duration required = 512 usec.

21:18:22.371 [14363] <4> bpbkar: INF - Processing /u02

21:18:22.384 [14364] <2> bpbkar add_to_filelist: starting sizeof(filelistrec) <68>

21:18:22.385 [14364] <4> bpbkar: INF - Throttle duration required = 512 usec.

21:18:22.386 [14364] <4> bpbkar: INF - Processing /u04

21:18:22.435 [14364] <4> bpbkar: INF - Excluded /u04/lost+found by exclude_list entry lost+found

21:18:22.482 [14364] <4> bpbkar: INF - Excluded /u04/comp/doug2.do_not_start/IDOLServer/FileSystemFetch/core by exclude_list entry core

21:18:22.751 [14369] <4> bpbkar main: real locales <C>

21:18:22.751 [14369] <4> bpbkar main: standardized locales - lc_messages <C> lc_ctype <C> lc_time <C> lc_collate <C> lc_numeric <C>

21:18:22.752 [14369] <2> logparams: bpbkar32 -r 3628800 -ru root -dt 0 -to 0 -clnt clientbox.com -class policyname -sched Full -st FULL -bpstart_to 300 -bpend_to 300 -read_to 500 -stream_count 8 -stream_number 8 -jobgrpid 13120 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -fso -b clientbox.com_1336938496 -kl 35 -use_ofb 

21:18:22.760 [14369] <4> bpbkar: INF - Setting network send buffer size to 32032 bytes

21:18:22.760 [14369] <4> bpbkar: INF - setenv KEYWORD=NONE

21:18:22.760 [14369] <4> bpbkar: INF - setenv STREAM_PID=14369

21:18:22.760 [14369] <4> bpbkar: INF - setenv STREAM_NUMBER=8

21:18:22.760 [14369] <4> bpbkar: INF - setenv STREAM_COUNT=8

21:18:22.760 [14369] <4> bpbkar: INF - setenv STREAMS=0

21:18:22.760 [14369] <4> bpbkar: INF - setenv BPSTART_TIMEOUT=300

21:18:22.760 [14369] <4> bpbkar: INF - setenv BPEND_TIMEOUT=300

21:18:22.760 [14369] <4> bpbkar: INF - setenv RESTARTED=1

21:18:22.760 [14369] <4> bpbkar: INF - setenv BACKUPID=clientbox.com_1336938496

21:18:22.760 [14369] <4> bpbkar: INF - setenv UNIXBACKUPTIME=1336938496

21:18:22.760 [14369] <4> bpbkar: INF - setenv BACKUPTIME=Sun May 13 15:48:16 2012

21:18:22.760 [14369] <4> bpbkar: INF - Inform when done

21:18:22.761 [14369] <4> bpbkar: INF - Echo keepalives

21:18:22.762 [14369] <4> bpbkar: INF - BACKUP START

21:18:22.762 [14369] <4> bpbkar: INF - Estimate:-1 -1

21:18:22.844 [14369] <2> bpbkar add_to_filelist: starting sizeof(filelistrec) <68>

21:18:22.845 [14369] <4> bpbkar: INF - Throttle duration required = 512 usec.

21:18:22.846 [14369] <4> bpbkar: INF - Processing /u05

21:18:23.006 [14364] <4> bpbkar: INF - Excluded /u04/comp/doug2.do_not_start/jdk1.6.0/lib/visualvm/platform/core by exclude_list entry core

21:18:23.022 [14364] <4> bpbkar: INF - Excluded /u04/comp/doug2.do_not_start/jdk1.6.0/lib/visualvm/visualvm/core by exclude_list entry core

21:18:23.065 [14383] <4> bpbkar main: real locales <C>

21:18:23.065 [14383] <4> bpbkar main: standardized locales - lc_messages <C> lc_ctype <C> lc_time <C> lc_collate <C> lc_numeric <C>

21:18:23.066 [14383] <2> logparams: bpbkar32 -r 3628800 -ru root -dt 0 -to 0 -clnt clientbox.com -class policyname -sched Full -st FULL -bpstart_to 300 -bpend_to 300 -read_to 500 -stream_count 8 -stream_number 1 -jobgrpid 13120 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -fso -b clientbox.com_1336937642 -kl 35 -use_ofb 

21:18:23.075 [14383] <4> bpbkar: INF - Setting network send buffer size to 32032 bytes

21:18:23.075 [14383] <4> bpbkar: INF - setenv KEYWORD=NONE

21:18:23.075 [14383] <4> bpbkar: INF - setenv STREAM_PID=14383

21:18:23.075 [14383] <4> bpbkar: INF - setenv STREAM_NUMBER=1

21:18:23.075 [14383] <4> bpbkar: INF - setenv STREAM_COUNT=8

21:18:23.075 [14383] <4> bpbkar: INF - setenv STREAMS=0

21:18:23.075 [14383] <4> bpbkar: INF - setenv BPSTART_TIMEOUT=300

21:18:23.075 [14383] <4> bpbkar: INF - setenv BPEND_TIMEOUT=300

21:18:23.075 [14383] <4> bpbkar: INF - setenv RESTARTED=1

21:18:23.075 [14383] <4> bpbkar: INF - setenv BACKUPID=clientbox.com_1336937642

21:18:23.075 [14383] <4> bpbkar: INF - setenv UNIXBACKUPTIME=1336937642

21:18:23.075 [14383] <4> bpbkar: INF - setenv BACKUPTIME=Sun May 13 15:34:02 2012

21:18:23.075 [14383] <4> bpbkar: INF - Inform when done

21:18:23.076 [14383] <4> bpbkar: INF - Echo keepalives

21:18:23.076 [14364] <4> bpbkar: INF - Excluded /u04/comp/doug2.do_not_start/tomcat/classes/org/apache/catalina/core by exclude_list entry core

21:18:23.077 [14383] <4> bpbkar: INF - BACKUP START

21:18:23.077 [14383] <4> bpbkar: INF - Estimate:-1 -1

21:18:23.105 [14364] <4> bpbkar: INF - Excluded /u04/comp/doug2.do_not_start/tomcat/classes/org/apache/jasper/tagplugins/jstl/core by exclude_list entry core

21:18:23.108 [14364] <4> bpbkar: INF - Excluded /u04/comp/doug2.do_not_start/tomcat/classes/org/apache/jk/core by exclude_list entry core

21:18:23.144 [14383] <2> bpbkar add_to_filelist: starting sizeof(filelistrec) <68>

21:18:23.145 [14383] <4> bpbkar: INF - Throttle duration required = 512 usec.

21:18:23.146 [14383] <4> bpbkar: INF - Processing /

21:18:23.195 [14386] <4> bpbkar main: real locales <C>

21:18:23.195 [14386] <4> bpbkar main: standardized locales - lc_messages <C> lc_ctype <C> lc_time <C> lc_collate <C> lc_numeric <C>

21:18:23.196 [14386] <2> logparams: bpbkar32 -r 3628800 -ru root -dt 0 -to 0 -clnt clientbox.com -class policyname -sched Full -st FULL -bpstart_to 300 -bpend_to 300 -read_to 500 -stream_count 8 -stream_number 5 -jobgrpid 13120 -ckpt_time 900 -blks_per_buffer 512 -tir -tir_plus -use_otm -fso -b clientbox.com_1336937646 -kl 35 -use_ofb 

21:18:23.198 [14383] <8> bpbkar: WRN - /dev/fd is in a different file system from /. Skipping.

21:18:23.205 [14386] <4> bpbkar: INF - Setting network send buffer size to 32032 bytes

21:18:23.205 [14386] <4> bpbkar: INF - setenv KEYWORD=NONE

21:18:23.205 [14386] <4> bpbkar: INF - setenv STREAM_PID=14386

21:18:23.205 [14386] <4> bpbkar: INF - setenv STREAM_NUMBER=5

21:18:23.205 [14386] <4> bpbkar: INF - setenv STREAM_COUNT=8

21:18:23.205 [14386] <4> bpbkar: INF - setenv STREAMS=0

21:18:23.205 [14386] <4> bpbkar: INF - setenv BPSTART_TIMEOUT=300

21:18:23.205 [14386] <4> bpbkar: INF - setenv BPEND_TIMEOUT=300

21:18:23.205 [14386] <4> bpbkar: INF - setenv RESTARTED=1

21:18:23.205 [14386] <4> bpbkar: INF - setenv BACKUPID=clientbox.com_1336937646

21:18:23.205 [14386] <4> bpbkar: INF - setenv UNIXBACKUPTIME=1336937646

21:18:23.206 [14386] <4> bpbkar: INF - setenv BACKUPTIME=Sun May 13 15:34:06 2012

21:18:23.206 [14386] <4> bpbkar: INF - Inform when done

21:18:23.206 [14386] <4> bpbkar: INF - Echo keepalives

21:18:23.207 [14386] <4> bpbkar: INF - BACKUP START

21:18:23.207 [14386] <4> bpbkar: INF - Estimate:-1 -1

21:18:23.260 [14386] <2> bpbkar add_to_filelist: starting sizeof(filelistrec) <68>

21:18:23.261 [14386] <4> bpbkar: INF - Throttle duration required = 512 usec.

21:18:23.263 [14386] <4> bpbkar: INF - Processing /u01

21:18:23.394 [14383] <8> bpbkar: WRN - /etc/mnttab is on file system type mntfs. Skipping.

21:18:23.498 [14383] <8> bpbkar: WRN - /home is in a different file system from /. Skipping.

21:18:23.535 [14383] <8> bpbkar: WRN - /logs is in a different file system from /. Skipping.

21:18:23.535 [14383] <4> bpbkar: INF - Excluded /lost+found by exclude_list entry lost+found

21:18:23.536 [14383] <4> bpbkar: INF - Excluded /mnt/oracle by exclude_list entry /mnt/*

21:18:23.536 [14383] <8> bpbkar: WRN - /net is on file system type autofs. Skipping.

21:18:23.567 [14383] <8> bpbkar: WRN - /opt is in a different file system from /. Skipping.

21:18:23.690 [14383] <8> bpbkar: WRN - /proc is on file system type PROC. Skipping.

21:18:23.694 [14383] <8> bpbkar: WRN - /tmp is in a different file system from /. Skipping.

21:18:23.695 [14383] <8> bpbkar: WRN - /u01 is in a different file system from /. Skipping.

21:18:23.695 [14383] <8> bpbkar: WRN - /u02 is in a different file system from /. Skipping.

21:18:23.696 [14383] <8> bpbkar: WRN - /u04 is in a different file system from /. Skipping.

21:18:23.697 [14383] <8> bpbkar: WRN - /u05 is in a different file system from /. Skipping.

21:18:23.819 [14383] <4> bpbkar: INF - Excluded /usr/appserver/lib/install/applications/adminapp/adminapp_war/WEB-INF/classes/com/iplanet/ias/admin/server/core by exclude_list entry core

21:18:24.410 [14369] <4> bpbkar: INF - Excluded /u05/comp_old_elearning/elearning/lib/verity/k2/_ssol26/bin/core by exclude_list entry core

21:18:25.417 [14369] <4> bpbkar: INF - Excluded /u05/backup/local/include/gnu/gcj/protocol/core by exclude_list entry core

21:21:24.897 [14383] <4> bpbkar: INF - Excluded /usr/jdk1.5.0_13/sample/jnlp/corba/src/core by exclude_list entry core

21:22:17.122 [14383] <4> bpbkar: INF - Excluded /usr/jdk1.5.0_21/sample/jnlp/corba/src/core by exclude_list entry core

21:25:49.508 [14369] <4> bpbkar: INF - Excluded /u05/lost+found by exclude_list entry lost+found

21:28:39.356 [14369] <4> bpbkar: INF - Excluded /u05/patches/9_Recommended/114016-01/SUNWtcatS/reloc/usr/share/src/tomcat/catalina/src/share/org/apache/catalina/core by exclude_list entry core

21:28:40.771 [14369] <4> bpbkar: INF - Excluded /u05/patches/9_Recommended/114016-01/SUNWtcatS/reloc/usr/share/src/tomcat/jasper/src/share/org/apache/jasper/core by exclude_list entry core

21:28:43.630 [14383] <4> bpbkar: INF - Excluded /usr/local/include/gnu/gcj/protocol/core by exclude_list entry core

21:28:44.646 [14369] <4> bpbkar: INF - Excluded /u05/patches/9_Recommended/114016-01/SUNWtcatr/reloc/var/apache/tomcat/webapps/tomcat-docs/catalina/docs/api/org/apache/catalina/core by exclude_list entry core

21:28:46.996 [14369] <4> bpbkar: INF - Excluded /u05/patches/9_Recommended/114016-01/SUNWtcatr/reloc/var/apache/tomcat/webapps/tomcat-docs/jasper/docs/api/org/apache/jasper/core by exclude_list entry core

21:29:33.721 [14369] <4> bpbkar: INF - Excluded /u05/patches/9_Recommended/114684-10/SUNWsmbaS/reloc/usr/sfw/share/src/samba/source/include/core by exclude_list entry core

21:31:40.590 [14383] <8> bpbkar: WRN - /usr/local/netiq/cmnagent/tmp/VigilEntAgent_sockV5 is a socket special file. Skipping.

21:31:47.725 [14383] <8> bpbkar: WRN - /usr/local/netiq/vsau/local/cache/va is a socket special file. Skipping.

21:32:06.865 [14383] <8> bpbkar: WRN - /usr/local/vsaunix/SunOS/cmnagent/tmp/VigilEntAgent_sockV5 is a socket special file. Skipping.

21:32:07.631 [14369] <4> bpbkar: INF - Excluded /u05/sales/bin/core by exclude_list entry core

21:32:11.688 [14383] <8> bpbkar: WRN - /usr/local/vsaunix/SunOS/vsau/local/cache/va is a socket special file. Skipping.

21:36:04.277 [14386] <4> bpbkar: INF - Excluded /u01/lost+found by exclude_list entry lost+found

21:36:09.938 [14369] <4> bpbkar: INF - Excluded /u05/sales/tomcat/webapps/tomcat-docs/catalina/docs/api/org/apache/catalina/core by exclude_list entry core

21:37:00.949 [14369] <4> bpbkar: INF - Excluded /u05/sandbox/bin/core by exclude_list entry core

21:41:43.732 [14369] <4> bpbkar: INF - Excluded /u05/sandbox/tomcat/webapps/tomcat-docs/catalina/docs/api/org/apache/catalina/core by exclude_list entry core

21:41:46.923 [14369] <4> bpbkar: INF - Excluded /u05/sandbox/tomcat/webapps/tomcat-docs/jasper/docs/api/org/apache/jasper/core by exclude_list entry core

21:43:00.573 [14369] <4> bpbkar: INF - Excluded /u05/trial09162009/bin/core by exclude_list entry core

21:44:18.033 [14363] <16> bpbkar: ERR - bpbkar killed by SIGPIPE

21:44:18.052 [14363] <16> bpbkar: ERR - bpbkar FATAL exit status = 40: network connection broken

21:44:18.066 [14363] <4> bpbkar: INF - EXIT STATUS 40: network connection broken

21:44:18.115 [14363] <8> bpbkar: WRN - Error closing stdout

21:44:18.154 [14363] <2> get_long_: protocol error - four byte read failed (Connection reset by peer)

21:44:18.154 [14363] <2> get_string_: failed reading string length (Connection reset by peer)

21:44:18.154 [14363] <16> bpbkar: ERR - read server exit status = 6: the backup failed to back up the requested files

21:44:18.154 [14363] <4> bpbkar: INF - setenv FINISHED=0

21:50:02.682 [14386] <4> bpbkar: INF - Client completed sending data for backup

21:50:02.702 [14386] <4> bpbkar: INF - bpbkar exit normal

21:50:02.702 [14386] <4> bpbkar: INF - EXIT STATUS 0: the requested operation was successfully completed

21:50:14.975 [14386] <16> bpbkar: ERR - read server exit status = 0: the requested operation was successfully completed

21:50:15.086 [14386] <4> bpbkar: INF - setenv FINISHED=1

22:06:19.030 [14383] <16> bpbkar: ERR - bpbkar killed by SIGPIPE

22:06:19.031 [14383] <16> bpbkar: ERR - bpbkar FATAL exit status = 40: network connection broken

22:06:19.053 [14383] <4> bpbkar: INF - EXIT STATUS 40: network connection broken

22:06:19.053 [14383] <8> bpbkar: WRN - Error closing stdout

22:06:19.053 [14383] <2> get_long_: protocol error - four byte read failed (Connection reset by peer)

22:06:19.053 [14383] <2> get_string_: failed reading string length (Connection reset by peer)

22:06:19.053 [14383] <16> bpbkar: ERR - read server exit status = 6: the backup failed to back up the requested files

22:06:19.053 [14383] <4> bpbkar: INF - setenv FINISHED=0

22:15:19.289 [14369] <2> get_long_: protocol error - four byte read failed (Connection reset by peer)

22:15:19.289 [14369] <2> get_string_: failed reading string length (Connection reset by peer)

22:15:19.289 [14369] <16> bpbkar: ERR - bpbkar killed by SIGPIPE

22:15:19.290 [14369] <16> bpbkar: ERR - bpbkar FATAL exit status = 40: network connection broken

22:15:19.290 [14369] <4> bpbkar: INF - EXIT STATUS 40: network connection broken

22:15:19.291 [14369] <8> bpbkar: WRN - Error closing stdout

22:15:19.291 [14369] <16> bpbkar: ERR - read server exit status = 6: the backup failed to back up the requested files

22:15:19.291 [14369] <4> bpbkar: INF - setenv FINISHED=0

22:57:20.466 [14364] <16> bpbkar: ERR - bpbkar killed by SIGPIPE

22:57:20.467 [14364] <16> bpbkar: ERR - bpbkar FATAL exit status = 40: network connection broken

22:57:20.467 [14364] <4> bpbkar: INF - EXIT STATUS 40: network connection broken

22:57:20.467 [14364] <8> bpbkar: WRN - Error closing stdout

22:57:20.467 [14364] <2> get_long_: protocol error - four byte read failed (Connection reset by peer)

22:57:20.467 [14364] <2> get_string_: failed reading string length (Connection reset by peer)

22:57:20.467 [14364] <16> bpbkar: ERR - read server exit status = 6: the backup failed to back up the requested files

22:57:20.467 [14364] <4> bpbkar: INF - setenv FINISHED=0

[revarooo]

Did you increase client_read_timeout on the media server? It doesn't look to me like its a read timeout issue. Pid 14363 is first to error at 21:44:18 it previously logged at 21:18 If it worked before then its probably a network issue, ask your networking team to investigate as well.

[Marianne]

Please also check bptm and bpbrm logs on media server.

bptm will tell us if any data was received from client and bpbrm will confirm the timeout.

Please post logs as attachment.

[muhanad_daher]

i think there hign I/O traffice;

also, you use a n exclude_list that's mean you use ALL_LOCAL_DRIVES; try to backup any file;

check the following also : df -h, iostat ; as marrine told in above post bptm and bpbrm; check bp.conf.

[rookie11]

@muhanad : how to check high I/O on server ?

wat would iostat reveal??

[muhanad_daher]

iostat -x // monitor Hard disk I/O

netstat //monitor network i/o