Error code 13 with RMAN backup

[mubarack_s]

Hi ,

        We are using netbackup 6.5.6 and a RMAN backup was successful upto last week. Now we are getting a error code 13. As per the document i have check the connectivity from both master and to client and vice versa.

      Can you help me to resolve this error?  Below is the error I am getting from RMAN

channel ch00: starting piece 1 at 04-FEB-11
released channel: ch00
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03009: failure of backup command on ch00 channel at 02/04/2011 07:23:53
ORA-27192: skgfcls: sbtclose2 returned error - failed to close file
ORA-19511: Error received from media manager layer, error text:
   Failed to process backup file <VDCHIST_6bm3pskm_1_1_20110204>
ORA-19502: write error on file "VDCHIST_6bm3pskm_1_1_20110204", blockno 6657 (blocksize=512)
ORA-27030: skgfwrt: sbtwrite2 returned error
ORA-19511: Error received from media manager layer, error text:
   VxBSASendData: Failed with error:

Thanx,

Mubarack.S

[Marianne]

Check dbclient log on the client. If you create the dir, remember the 777 permission.

[mubarack_s]

Thank you if bpkar logs are enough to resolve this error

[Amit_Karia]

Do you have sufficient permissions on RMAN script?

also provide bpdhb logs

[Marianne]

NBU for Oracle agent does not create logs in bpbkar.

You need dbclient log (with 777 permissions to give oracle user write access).

If backups are kicked off from NBU scheduler on master, bphdb might also be useful.

See NBU for Oracle Guide on p.182  for a list of log directories.

The one that I find most useful is dbclient.

[mubarack_s]

Hi

    Kidly find the dbclient and bphdb logs. Backup was intiated by netbackup but unable to retrive the requested file.  The script is having full permission. but donno why its happens.

bphdb log

========

04:29:09.583 [13285] <2> logparams: -sb -rdbms oracle -S SS93VPBK01-01 -to 1800 -c DB05_Backup_VDChist -s VDC_Hist_Backup -clnt SS93VPDB05-NB -FULL -kl 3 -ri

SS93VPBK01-01 -b SS93VPDB05-NB_1297801747 -jobid 55429

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_POLICY=DB05_Backup_VDChist

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_CLIENT=SS93VPDB05-NB

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_MODE=B

04:29:09.598 [13285] <4> bphdb main: INF - NB_ORA_POLICY=DB05_Backup_VDChist

04:29:09.598 [13285] <4> bphdb main: INF - NB_ORA_SCHED not defined.

04:29:09.598 [13285] <4> bphdb main: INF - NB_ORA_PC_SCHED=VDC_Hist_Backup

04:29:09.598 [13285] <4> bphdb main: INF - NB_ORA_SERV=SS93VPBK01-01

04:29:09.598 [13285] <4> bphdb main: INF - NB_ORA_PC_BTYPE not set

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_FULL=1

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_INCR=0

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_CINC=0

04:29:09.598 [13285] <4> bphdb main: INF - setenv NB_ORA_SCHEDULED=1

04:29:09.599 [13285] <4> bphdb sync_server: INF - BACKUP START

04:29:09.661 [13285] <4> bphdb sync_server: INF - CONTINUE BACKUP message received.

04:29:09.661 [13285] <2> bphdb get_filelist: INF - Read filename: </vpsdb05bkp/oracle/vdchist/rman/src/ss93vpdb05_nb_hist_rman_backup.sh>

04:29:09.662 [13285] <2> bphdb get_filelist: INF - Read filename: <CONTINUE>

04:29:09.662 [13285] <4> bphdb do_backup: INF - Processing /vpsdb05bkp/oracle/vdchist/rman/src/ss93vpdb05_nb_hist_rman_backup.sh

04:29:09.665 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

04:29:09.666 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

04:29:09.666 [13285] <4> bphdb do_backup: INF - Keepalives will be sent every 900 seconds.

04:29:09.666 [13285] <4> bphdb do_backup: INF - Waiting for the child status.

04:29:09.669 [13289] <4> bphdb do_backup: INF - Child executing /vpsdb05bkp/oracle/vdchist/rman/src/ss93vpdb05_nb_hist_rman_backup.sh

04:44:09.707 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

04:44:09.708 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

04:59:09.735 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

04:59:09.736 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

05:14:09.771 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

05:14:09.772 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

05:29:09.807 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

05:29:09.807 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

05:44:09.843 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

05:44:09.843 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

05:59:09.881 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

05:59:09.881 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

06:14:09.897 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

06:14:09.898 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

06:29:09.933 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

06:29:09.934 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

06:44:09.970 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

06:44:09.970 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

06:59:09.984 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

06:59:09.985 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

07:14:09.999 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

07:14:09.999 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

07:29:10.028 [13285] <4> bphdb keepalive_timeout: INF - bphdb still working.

07:29:10.029 [13285] <2> bphdb keepalive_timeout: INF - bphdb- Sending a keepalive.

07:30:39.973 [13285] <4> bphdb do_backup: INF - Script exited with status = 0 <the requested operation was successfully completed>

07:30:40.165 [13285] <8> delete_old_files: WRN - Directory /usr/openv/netbackup/logs/bpubsora does not exist

07:30:40.165 [13285] <4> bphdb Exit: INF - bphdb exit normal

07:30:40.166 [13285] <4> bphdb Exit: INF - EXIT STATUS 0: the requested operation was successfully completed

dbclient log

=========

04:29:40.081 [13386] <4> serverResponse: read comm file:<04:29:31 Initiating backup>

04:29:40.081 [13386] <4> readCommMessages: Entering readCommMessages

04:29:45.081 [13386] <4> serverResponse: read comm file:<04:29:36 INF - Starting bpbrm>

04:29:45.081 [13386] <4> serverResponse: read comm file:<04:29:36 INF - Data socket = ss93vpbk04-01.sg.visaps.com.IPC:/tmp/vnet-13507297801776232636000000000-OXayyA;550d6ecd6fa636459e8c1a4ec2f4b6fb;4;300>

04:29:45.081 [13386] <4> serverResponse: INF - connecting to server on DATA socket ss93vpbk04-01.sg.visaps.com.IPC:/tmp/vnet-13507297801776232636000000000-OXayyA;550d6ecd6fa636459e8c1a4ec2f4b6fb;4;300

04:29:45.082 [13386] <4> connectSockStr: INF - port id = IPC:/tmp/vnet-13507297801776232636000000000-OXayyA;550d6ecd6fa636459e8c1a4ec2f4b6fb;4;300

04:29:45.082 [13386] <4> connectSockStr: INF - hostname = ss93vpbk04-01.sg.visaps.com

04:29:45.085 [13386] <2> vnet_receive_network_socket: vnet_vnetd.c.1251: hash_str1: 550d6ecd6fa636459e8c1a4ec2f4b6fb

04:29:45.085 [13386] <2> vnet_receive_network_socket: vnet_vnetd.c.1252: hash_str2: f37a68201c1fe7ef8c1fed7f576db405

04:29:45.085 [13386] <2> verify_hashes: vnet_vnetd.c.1765: hash_str1: 550d6ecd6fa636459e8c1a4ec2f4b6fb

04:29:45.086 [13386] <2> verify_hashes: vnet_vnetd.c.1767: hash_str2: f37a68201c1fe7ef8c1fed7f576db405

04:29:45.086 [13386] <2> verify_hashes: vnet_vnetd.c.1793: hash_str: 550d6ecd6fa636459e8c1a4ec2f4b6fb

04:29:45.086 [13386] <4> serverResponse: INF - DATA sockfd: 26

04:29:45.086 [13386] <4> serverResponse: read comm file:<04:29:36 INF - Name socket = ss93vpbk04-01.sg.visaps.com.IPC:/tmp/vnet-13508297801776342447000000000-wZaGyA;3d306cd768b0d8e4f158a3bd828f54bd;4;300>

04:29:45.086 [13386] <4> serverResponse: INF - connecting to server on NAME socket ss93vpbk04-01.sg.visaps.com.IPC:/tmp/vnet-13508297801776342447000000000-wZaGyA;3d306cd768b0d8e4f158a3bd828f54bd;4;300

04:29:45.086 [13386] <4> connectSockStr: INF - port id = IPC:/tmp/vnet-13508297801776342447000000000-wZaGyA;3d306cd768b0d8e4f158a3bd828f54bd;4;300

04:29:45.086 [13386] <4> connectSockStr: INF - hostname = ss93vpbk04-01.sg.visaps.com

04:29:45.090 [13386] <2> vnet_receive_network_socket: vnet_vnetd.c.1251: hash_str1: 3d306cd768b0d8e4f158a3bd828f54bd

04:29:45.090 [13386] <2> vnet_receive_network_socket: vnet_vnetd.c.1252: hash_str2: 818b79a80bdb1d908aa489d7bcba32d0

04:29:45.090 [13386] <2> verify_hashes: vnet_vnetd.c.1765: hash_str1: 3d306cd768b0d8e4f158a3bd828f54bd

04:29:45.090 [13386] <2> verify_hashes: vnet_vnetd.c.1767: hash_str2: 818b79a80bdb1d908aa489d7bcba32d0

04:29:45.090 [13386] <2> verify_hashes: vnet_vnetd.c.1793: hash_str: 3d306cd768b0d8e4f158a3bd828f54bd

04:29:45.090 [13386] <4> serverResponse: INF - NAME sockfd: 27

04:29:45.090 [13386] <4> serverResponse: read comm file:<04:29:36 INF - Job id = 55430>

04:29:45.091 [13386] <4> serverResponse: -jobid 55430

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Backup id = SS93VPDB05-NB_1297801774>

04:29:45.091 [13386] <4> serverResponse: -backupid SS93VPDB05-NB_1297801774

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Backup time = 1297801774>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Policy name = DB05_Backup_VDChist>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Snapshot = 0>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Frozen image = 0>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Backup copy = 0>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Master server = SS93VPBK01-01>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Media server = SS93VPBK04-01>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Multiplexing = 0>

04:29:45.091 [13386] <4> serverResponse: read comm file:<04:29:37 INF - New data socket = ss93vpbk04-01.sg.visaps.com.IPC:/tmp/vnet-13506297801776103374000000000-NVaqyA;ec3a0d04dbdd5dd083a837034b426bb5;4;300>

04:29:45.091 [13386] <4> serverResponse: INF - connecting to server on NEW DATA socket ss93vpbk04-01.sg.visaps.com.IPC:/tmp/vnet-13506297801776103374000000000-NVaqyA;ec3a0d04dbdd5dd083a837034b426bb5;4;300

04:29:45.091 [13386] <4> connectSockStr: INF - port id = IPC:/tmp/vnet-13506297801776103374000000000-NVaqyA;ec3a0d04dbdd5dd083a837034b426bb5;4;300

04:29:45.091 [13386] <4> connectSockStr: INF - hostname = ss93vpbk04-01.sg.visaps.com

04:29:45.095 [13386] <2> vnet_receive_network_socket: vnet_vnetd.c.1251: hash_str1: ec3a0d04dbdd5dd083a837034b426bb5

04:29:45.095 [13386] <2> vnet_receive_network_socket: vnet_vnetd.c.1252: hash_str2: 4f2ba9b37a8eff8d3471f8ea6406b30b

04:29:45.095 [13386] <2> verify_hashes: vnet_vnetd.c.1765: hash_str1: ec3a0d04dbdd5dd083a837034b426bb5

04:29:45.095 [13386] <2> verify_hashes: vnet_vnetd.c.1767: hash_str2: 4f2ba9b37a8eff8d3471f8ea6406b30b

04:29:45.095 [13386] <2> verify_hashes: vnet_vnetd.c.1793: hash_str: ec3a0d04dbdd5dd083a837034b426bb5

04:29:45.096 [13386] <4> serverResponse: INF - NEW DATA sockfd: 28

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Encrypt = 0>

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Use shared memory = 0>

04:29:45.096 [13386] <4> serverResponse: INF - UseShM set to 0

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Compression = 1>

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:37 INF - Encrypt = 0>

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:38 INF - Keep logs = 3>

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:38 INF - Client read timeout = 1800>

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:38 INF - Media mount timeout = 0>

04:29:45.096 [13386] <4> serverResponse: INF - end reading comm file

04:29:45.097 [13386] <4> CreateNewImage: INF - dSock=26, nSock=27, ndSock=28

04:29:45.097 [13386] <4> handshake: entering handShake.

04:29:45.097 [13386] <4> handshake: INF - BACKUP START sent to bpbrm

04:29:45.097 [13386] <4> readSock: entering readSock.

04:29:45.097 [13386] <4> read_from_socket: entering read_from_socket.

04:29:45.152 [13386] <4> handshake: INF - CONTINUE BACKUP message received

04:29:45.152 [13386] <4> handshake: INF - Beginning backup timeout value = 900

04:29:45.152 [13386] <4> readCommMessages: Entering readCommMessages

04:29:55.153 [13386] <4> handshake: INF - got filename from server: </VDCHIST_6fm4phh9_1_1_20110216>

04:29:55.153 [13386] <4> handshake: INF - valid newdataSock: 28

04:29:55.153 [13386] <4> handshake: INF - nameSock = 27, dataSock = 28, commSock = 26

04:29:55.153 [13386] <4> writeTarHeader: entering writeTarHeader.

04:29:55.153 [13386] <4> getOwnerName: entering getOwnerName.

04:29:55.154 [13386] <4> finishHeader: entering finishHeader.

04:29:55.154 [13386] <4> getOwnerName: entering getOwnerName.

04:29:55.154 [13386] <4> writeTarHeader: INF - LF_TYPE = 41

04:29:55.154 [13386] <4> finishHeader: entering finishHeader.

04:29:55.154 [13386] <4> writeTarHeader: INF - writing tar header

04:29:55.154 [13386] <4> CreateNewImage: INF - returning STAT_SUCCESS

04:29:55.155 [13386] <4> VxBSACreateObject: INF - Object 1 added to NEW image 1297801774

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectOwner.bsa_ObjectOwner:

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectOwner.app_ObjectOwner:

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectName.objectSpaceName: Oracle Database

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectName.pathName: /VDCHIST_6fm4phh9_1_1_20110216

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - createTime: 1297801774

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - copyType: 3

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - copyid: 1.1297801774

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - restoreOrder: 1297801769.1

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - estimatedSize: 0.100

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - resourceType: Oracle Backup

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectType: 4

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectStatus: 2

04:29:55.155 [13386] <4> bsa_printObjectDescriptor: INF - objectDescription:

04:29:55.155 [13386] <2> xbsa_CreateObject: INF - leaving (0)

04:29:55.155 [13386] <2> int_StartJob: INF - copyID: 1 - 1297801774

04:29:55.156 [13386] <2> xbsa_SetEnv: INF - entering

04:29:55.156 [13386] <4> VxBSASetEnv: INF - entering SetEnv - NBBSA_CLIENT_READ_TIMEOUT

04:29:55.156 [13386] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_CLIENT_READ_TIMEOUT

04:29:55.156 [13386] <4> VxBSAGetEnv: INF - returning - 10800

04:29:55.156 [13386] <4> dbc_SetClientReadTimeout: INF - sending client read timeout

04:29:55.156 [13386] <2> xbsa_SetEnv: INF - leaving (0)

04:29:55.156 [13386] <2> int_StartJob: INF - leaving

04:29:55.156 [13386] <2> sbtbackup: INF - leaving

04:29:55.203 [13386] <2> int_WriteData: INF - writing buffer # 1 of size 262144

07:30:29.085 [13386] <16> writeToServer: ERR - send() to server on socket failed: Broken pipe (32)

07:30:29.090 [13386] <16> dbc_put: ERR - failed sending data to server

07:30:29.090 [13386] <4> closeApi: entering closeApi.

07:30:29.098 [13386] <4> closeApi: INF - EXIT STATUS 6: the backup failed to back up the requested files

07:30:29.098 [13386] <4> closeApi: INF - closing commSock 26

07:30:29.099 [13386] <4> closeApi: INF - close of commSock returned <0> errno is <32>

07:30:29.099 [13386] <4> closeApi: INF - closing dataSock 28

07:30:29.099 [13386] <4> closeApi: INF - close of dataSock returned <0> errno is <32>

07:30:29.099 [13386] <4> closeApi: INF - setting linger on nameSock 27

07:30:29.099 [13386] <4> closeApi: Could not set linger option on socket: 27

07:30:29.099 [13386] <4> closeApi: INF - closing nameSock 27

07:30:29.099 [13386] <4> closeApi: INF - close of nameSock returned <0> errno is <22>

07:30:29.110 [13386] <16> VxBSASendData: ERR - Could not do a bsa_put().

07:30:29.116 [13386] <2> xbsa_ProcessError: INF - entering

07:30:29.116 [13386] <2> xbsa_ProcessError: INF - leaving

07:30:29.116 [13386] <16> xbsa_SendData: ERR - VxBSASendData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve

07:30:29.116 [13386] <2> sbterror: INF - entering

07:30:29.117 [13386] <2> sbterror: INF - Error=7501: VxBSASendData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve.

07:30:29.117 [13386] <2> sbterror: INF - leaving

07:30:29.121 [13386] <16> dbc_put: ERR - invalid handle received from the application

07:30:29.121 [13386] <4> closeApi: entering closeApi.

07:30:29.121 [13386] <4> closeApi: INF - EXIT STATUS 6: the backup failed to back up the requested files

07:30:29.121 [13386] <16> VxBSASendData: ERR - Could not do a bsa_put().

07:30:29.121 [13386] <2> xbsa_ProcessError: INF - entering

07:30:29.121 [13386] <2> xbsa_ProcessError: INF - leaving

07:30:29.121 [13386] <16> xbsa_SendData: ERR - VxBSASendData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve

07:30:29.121 [13386] <2> sbterror: INF - entering

07:30:29.122 [13386] <2> sbterror: INF - Error=7501: VxBSASendData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve.

07:30:29.122 [13386] <2> sbterror: INF - leaving

07:30:29.126 [13386] <16> dbc_put: ERR - invalid handle received from the application

07:30:29.126 [13386] <4> closeApi: entering closeApi.

07:30:29.126 [13386] <4> closeApi: INF - EXIT STATUS 6: the backup failed to back up the requested files

07:30:29.126 [13386] <16> VxBSASendData: ERR - Could not do a bsa_put().

07:30:29.126 [13386] <2> xbsa_ProcessError: INF - entering

07:30:29.126 [13386] <2> xbsa_ProcessError: INF - leaving

07:30:29.126 [13386] <16> xbsa_SendData: ERR - VxBSASendData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve

07:30:29.126 [13386] <2> sbterror: INF - entering

07:30:29.126 [13386] <2> sbterror: INF - Error=7501: VxBSASendData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve.

07:30:29.126 [13386] <2> sbterror: INF - leaving

07:30:29.127 [13386] <2> sbtclose2: INF - entering

07:30:29.127 [13386] <2> int_CloseImage: INF - entering

07:30:29.127 [13386] <2> int_CloseImage: INF - Backup - closing <VDCHIST_6fm4phh9_1_1_20110216>

07:30:29.127 [13386] <2> xbsa_EndData: INF - entering

07:30:29.127 [13386] <4> VxBSAEndData: INF - entering EndData.

07:30:29.127 [13386] <4> finishTarImage: INF - FractionalObjectBytes: 3691

07:30:29.127 [13386] <16> writeToServer: ERR - send() to server on socket failed: Bad file number (9)

07:30:29.127 [13386] <16> finishTarImage: ERR - failed zeroing to 512 byte boundary for the data part of the image

07:30:29.127 [13386] <16> VxBSAEndData: ERR - EndData unable to bsa_finishTarImage().

07:30:29.127 [13386] <2> xbsa_ProcessError: INF - entering

07:30:29.127 [13386] <2> xbsa_ProcessError: INF - leaving

07:30:29.127 [13386] <16> xbsa_EndData: ERR - VxBSAEndData: Failed with error:

Server Status: Communication with the server has not been initiated or the server status has not been retrieved from the serve

07:30:29.127 [13386] <2> xbsa_EndData: INF - leaving (3)

07:30:29.127 [13386] <16> int_CloseImage: ERR - Failed to process backup file <VDCHIST_6fm4phh9_1_1_20110216>

07:30:29.127 [13386] <2> xbsa_EndTransaction: INF - entering

07:30:29.127 [13386] <4> VxBSAEndTxn: INF - entering VxBSAEndTxn.

07:30:29.128 [13386] <4> VxBSAEndTxn: INF - Transaction being ABORTED.

07:30:29.128 [13386] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_LOG_DIRECTORY

07:30:29.128 [13386] <4> VxBSAGetEnv: INF - returning - dbclient

07:30:29.128 [13386] <4> VxBSAEndTxn: INF - Cleaning directory: </usr/openv/netbackup/logs/dbclient>

07:30:29.130 [13386] <4> delete_old_files: entering delete_old_files.

07:30:29.136 [13386] <8> close_image: Session being terminated abnormally, cleaning up

07:30:29.136 [13386] <4> closeApi: entering closeApi.

07:30:29.136 [13386] <4> closeApi: INF - EXIT STATUS 6: the backup failed to back up the requested files

07:30:29.136 [13386] <4> close_image: INF - backup FAILED

07:30:29.136 [13386] <4> close_image: INF ---- end of Backup ---

07:30:29.136 [13386] <2> xbsa_EndTransaction: INF - leaving (0)

07:30:29.136 [13386] <2> int_CloseImage: INF - leaving

07:30:29.136 [13386] <2> sbtclose2: INF - leaving

07:30:29.137 [13386] <2> sbterror: INF - entering

07:30:29.137 [13386] <2> sbterror: INF - Error=7501: Failed to process backup file <VDCHIST_6fm4phh9_1_1_20110216>

.

07:30:29.137 [13386] <2> sbterror: INF - leaving

07:30:39.729 [13386] <2> sbtend: INF - entering

07:30:39.729 [13386] <2> int_FreeDuplexStrings: INF - entering

07:30:39.729 [13386] <2> int_FreeDuplexStrings: INF - leaving

07:30:39.729 [13386] <4> sbtend: INF - --- END of SESSION ---

07:30:39.729 [13386] <2> sbtend: INF - leaving

07:30:39.729 [13386] <4> VxBSATerminate: INF - entering VxBSATerminate.

07:30:39.729 [13386] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_DEBUGFD

07:30:39.730 [13386] <4> VxBSAGetEnv: INF - returning -  

[Marianne]

256k was sent at 04:29, nothing after that. Timeout kicked in at 07:30.

04:29:55.156 [13386] <4> VxBSASetEnv: INF - entering SetEnv - NBBSA_CLIENT_READ_TIMEOUT
04:29:55.156 [13386] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_CLIENT_READ_TIMEOUT
04:29:55.156 [13386] <4> VxBSAGetEnv: INF - returning - 10800
04:29:55.156 [13386] <4> dbc_SetClientReadTimeout: INF - sending client read timeout
04:29:55.156 [13386] <2> xbsa_SetEnv: INF - leaving (0)
04:29:55.156 [13386] <2> int_StartJob: INF - leaving
04:29:55.156 [13386] <2> sbtbackup: INF - leaving
04:29:55.203 [13386] <2> int_WriteData: INF - writing buffer # 1 of size 262144

07:30:29.085 [13386] <16> writeToServer: ERR - send() to server on socket failed: Broken pipe (32)
07:30:29.090 [13386] <16> dbc_put: ERR - failed sending data to server

As a start, enable debug output for Rman to see if a constant datastream is generated:

http://my.safaribooksonline.com/book/databases/oracle/9781590598511/troubleshooting-rman/enabling_rmans_debug_output

Ensure that you have bptm and bpbrm logs on media server. Increase verbose level to something like 3. These logs will tell you if data is received from client - bptm will log data transfer and bpbrm comms with client.

[mubarack_s]

Hi All,

Unable to resolve this error. Can anyone give me some idea.

[mubarack_s]

Hi ,

    Still problem is persisting. Its not only with DB client and os files also getting the same error.

   In logs I am getting " File read error 13"

[Marianne]

As I've pointed out before - It's a timeout. You (or the system owner) needs to find out why the client stops sending data.

Your timeout is already 3 hours - that says to me there's something seriously wrong on the client itself.

I remember early NBU days sitting on site at a customer right through the night tailing logs, monitoring processes, cpu and memory usage, trying to find out what is happening... Fortunately there are clever sysadmins these days who can write scripts to capture client activities.

The Troubleshooting Guide also lists quite a lot of stuff that must be checked and verified:

A read of a file or socket failed.

The possible causes include as follows:
* A network communication problem has occurred on the master server, media server, or one of the clients.
* An I/O error that occurred during a read from the file system.
* Read of an incomplete file or a corrupt file.
* A socket read failure that is caused by a network problem or a problem with the process that writes to the socket.
............
Do the following, as appropriate:
* Check the NetBackup Problems report for clues on where and why the problem occurred.
* Check that network communication works properly.
See "Resolving network communication problems" in the Troubleshooting Guide.
* .....
* Ensure that the latest service packs for all products and components (SQL, Exchange, Notes, etc.) have been installed.
* Ensure that all the network hardware (NICs, hubs, switches, routers, etc.) throughout the environment are set to full duplex, not half duplex.
* Check the following items regarding the NICs in your system:
* Upgrade to the latest NIC drivers throughout the system.
* Ensure that all NICs are set to full duplex, not half duplex.
See "Backup performance and NIC cards" in the Troubleshooting Guide.
* Increase the timeout settings on the NIC.
* If NIC teaming is implemented, deactivate for testing purposes.
* Replace the NIC itself on the affected client or server.
...............
 

[mubarack_s]

thank you. I am looking forword with the server performance.

[spulipati]

mubarack.s

What is the "CLIENT_READ_TIMEOUT" and "CLIENT_CONNECT_TIMEOUT" values set to. 

Since you mentioned that even file system backups are failing with status code 13, its worth increasing the value to "3600" or "7200". I always use 3600 for windows systems and 7200 for unix systems when i face this error code 13.

[Yogesh9881]

You can set this values from NBU GUI --> hostproperties

[Marianne]

We can see in the dbclient log that CLIENT_READ_TIMEOUT is already set to 3 hours (probably on client itself):

04:29:55.156 [13386] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_CLIENT_READ_TIMEOUT
04:29:55.156 [13386] <4> VxBSAGetEnv: INF - returning - 10800
04:29:55.156 [13386] <4> dbc_SetClientReadTimeout: INF - sending client read timeout

Please check timeouts in Host Properties for Master, Media Server and Client.

You do seem to have timeout mismatch - also in dbclient:

04:29:45.096 [13386] <4> serverResponse: read comm file:<04:29:38 INF - Client read timeout = 1800>

Set all timeouts to the same value - master, media server and client. There should be no need for greater than 3600 (1 hour). Timeout only happens because NO DATA whatsoever is sent for the duration of the timeout.

PLEASE don't increase timeouts any further - rather troubleshoot client processes, network, etc.

[Zailar]

Hi Mubarack,

The last error like that :

Server Status:  Communication with the server has not been initiated or the server status has not been retrieved from the server

I was tried set ndd

ndd -get /dev/tcp tcp_time_wait_interval

with

ndd -set /dev/tcp tcp_time_wait_interval 10000

[mubarack_s]

Hi Zailar,

         sorry for the delay response.

          I have tried setting the NIC settings. Actually in our environment, we are using Private VLAN concepts.

          I have a tried a backup with primary VLAN rather than private VLAN. Its working.

          Then we sorted out the problem is with the NIC card assigned for Private VLAN.

From the snoop output we got below error

         (warning) packet length greater than MTU in buffer offset 2196: length=1564
         (warning) packet length greater than MTU in buffer offset 3760: length=1564
         (warning) packet length greater than MTU in buffer offset 5324: length=1564
 

          We are plannig to made some setting with NIC

         Disabled HW cksum in IP stack by /etc/system modification:

         set ip:dohwcksum=0

 

         And RUN the below command

         ndd -set /dev/ip ip_lso_outbound 0

         I hope this will help me to resolve the issue.