Oracle backup failure

[nasahasha]

Hi,

I had same problem as in https://www-secure.symantec.com/connect/forums/problem-backup-oracle-11-oracle-linux ,
file system backups work fine and oracle backups fail.Netbackup version 7.5.0.5 and oracle 11.1.0.7 on RHEL.

I tried

1)Increasing time outs didnt worked.

2)recycling services reinstalling on client didnt work.

3)ports for 1556 were open

4)bpclntcmd -hn/ip worked fine

5)There are other clients with DB on them, all are working fine, only this client has problem

but bpclntcmd -pn didnt worked, then I concluded that client is not able to connect to bprd on master but dont know why?

For some reason I had to recycle netbackup services on master server and then oracle backups completed fine.

appreciate your help in finding what went wrong and why was it not able to connect to bprd, and Do I have to recycle services on master when I see this again?

Below is dbclient log 

root@:/usr/openv/netbackup/logs/dbclient

08:55:14 # ls

log.062813

root@:/usr/openv/netbackup/logs/dbclient

08:55:38 # cat log.062813

07:22:14.697 [63217] <2> int_LogSystemInfo: INF -

Veritas NetBackup for Oracle - Release 7.5 (2012091610)

        System name:    Linux

        Node name:      

        Release:        2.6.18-194.32.1.el5

        Version:        #1 SMP Mon Dec 20 10:52:42 EST 2010

        Machine:        x86_64

        User name:      oracle

        Client Host:    

07:22:14.697 [63217] <2> int_GetMMInfo: INF - Initialized Signal

07:22:14.697 [63217] <2> int_GetMMInfo: INF - support for Proxy Copy enabled

07:22:20.513 [63389] <2> int_LogSystemInfo: INF -

Veritas NetBackup for Oracle - Release 7.5 (2012091610)

        System name:    Linux

        Node name:      

        Release:        2.6.18-194.32.1.el5

        Version:        #1 SMP Mon Dec 20 10:52:42 EST 2010

        Machine:        x86_64

        User name:      oracle

        Client Host:    

07:22:20.514 [63389] <2> int_GetMMInfo: INF - Initialized Signal

07:22:20.514 [63389] <2> int_GetMMInfo: INF - support for Proxy Copy enabled

07:22:36.529 [63389] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.428: errno: 2 2 0x00000002

07:22:36.529 [63389] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.429: path: /home/oracle/bp.conf

07:22:36.530 [63389] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/04d/359bc4d+veritas_pbx,1,20,2,1,0+taspmonby01_bk.cernerasp.com.txt

07:22:36.533 [63389] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/0d5/374a20d5+0,1,402,2,1,0+txt

07:22:36.533 [63389] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/0d5/374a20d5+0,1,20,2,1,0+

07:22:36.533 [63389] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/04d/359bc4d+vnetd,1,20,2,1,0+taspmonby01_bk.cernerasp.com.txt

07:22:36.533 [63389] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/04d/359bc4d+bprd,1,20,2,1,0+taspmonby01_bk.cernerasp.com.txt

07:22:36.535 [63389] <2> vnet_pbxConnect: pbxConnectEx Succeeded

07:22:36.535 [63389] <2> logconnections: BPRD CONNECT FROM 10.159.82.133.10100 TO 170.71.0.16.1556 fd = 25

07:22:36.549 [63389] <2> xbsa_ProgressLogSetup: INF - No progress log: Job will proceed without progress logging

07:22:36.553 [63389] <2> vnet_pbxConnect: pbxConnectEx Succeeded

07:22:36.553 [63389] <2> logconnections: BPRD CONNECT FROM 10.159.82.133.21569 TO 170.71.0.16.1556 fd = 26

07:22:36.720 [63217] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.428: errno: 2 2 0x00000002

07:22:36.720 [63217] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.429: path: /home/oracle/bp.conf

07:22:36.721 [63217] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/04d/359bc4d+veritas_pbx,1,20,2,1,0+taspmonby01_bk.cernerasp.com.txt

07:22:36.722 [63217] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/0d5/374a20d5+0,1,402,2,1,0+

07:22:36.723 [63217] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/0d5/374a20d5+0,1,20,2,1,0+

07:22:36.723 [63217] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/04d/359bc4d+vnetd,1,20,2,1,0+taspmonby01_bk.cernerasp.com.txt

07:22:36.723 [63217] <8> file_to_cache_item: [vnet_addrinfo.c:6555] fopen() failed ERRNO=2 FILE=/usr/openv/var/host_cache/04d/359bc4d+bprd,1,20,2,1,0+taspmonby01_bk.cernerasp.com.txt

07:22:36.724 [63217] <2> vnet_pbxConnect: pbxConnectEx Succeeded

07:22:36.724 [63217] <2> logconnections: BPRD CONNECT FROM 10.159.82.133.24861 TO 170.71.0.16.1556 fd = 25

07:22:36.736 [63217] <2> xbsa_ProgressLogSetup: INF - No progress log: Job will proceed without progress logging

07:22:36.738 [63217] <2> vnet_pbxConnect: pbxConnectEx Succeeded

07:22:36.738 [63217] <2> logconnections: BPRD CONNECT FROM 10.159.82.133.31219 TO 170.71.0.16.1556 fd = 26

07:22:43.561 [63389] <8> verify_hashes: [vnet_vnetd.c:1641] hash_str 1f405a04db15f269485de7f3d0e99f65

07:22:43.561 [63389] <8> verify_hashes: [vnet_vnetd.c:1641] hash_str 58602a0e2dc1dba8e42c1f98ae195031

07:22:43.562 [63389] <8> verify_hashes: [vnet_vnetd.c:1641] hash_str 6b5897864dd49a5c8f3663aff1b5aa66

07:22:44.746 [63217] <8> verify_hashes: [vnet_vnetd.c:1641] hash_str 01b90b4a3d1957d1523e3d9e1a03ec5f

07:22:44.747 [63217] <8> verify_hashes: [vnet_vnetd.c:1641] hash_str c7fabdc636daa2fe29d8d81f8ac7efe0

07:22:44.747 [63217] <8> verify_hashes: [vnet_vnetd.c:1641] hash_str b3f44568ef27d6f86f91cd74e37fb04e

07:37:45.511 [63389] <16> readCommFile: ERR - timed out after 900 seconds while reading from /usr/openv/netbackup/logs/user_ops/dbext/logs/63389.0.1372418556

07:37:46.693 [63217] <16> readCommFile: ERR - timed out after 900 seconds while reading from /usr/openv/netbackup/logs/user_ops/dbext/logs/63217.0.1372418556

07:37:50.514 [63389] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.428: errno: 2 2 0x00000002

07:37:50.514 [63389] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.429: path: /home/oracle/bp.conf

07:37:51.696 [63217] <16> CopyToShM: connection broken. Error #40

07:37:51.696 [63217] <16> writeToServer: ERR - CopyToShM() failed, no files backed up

07:37:51.696 [63217] <16> write_xbsa: ERR - can't write XBSA data to DATA socket

07:37:51.696 [63217] <16> handshake: ERR - writeTarHeader() failed

07:37:51.696 [63217] <16> CreateNewImage: ERR - handshake() failed

07:37:51.736 [63217] <16> VxBSACreateObject: ERR - Could not create new image with file /C01821_ARC_201306280722_46oda5ls_1_1819271356.

07:37:51.736 [63217] <16> xbsa_CreateObject: ERR - VxBSACreateObject: 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:52:52.420 [63389] <16> readCommFile: ERR - timed out after 900 seconds while reading from /usr/openv/netbackup/logs/user_ops/dbext/logs/63389.0.1372418556

07:52:52.420 [63389] <32> serverResponse: ERR - could not read from comm file </usr/openv/netbackup/logs/user_ops/dbext/logs/63389.0.1372418556>

07:52:52.420 [63389] <16> CreateNewImage: ERR - serverResponse() failed

07:52:52.420 [63389] <16> VxBSACreateObject: ERR - Could not create new image with file /C01821_ARC_201306280722_47oda5ls_1_1819271356.

07:52:52.420 [63389] <16> xbsa_CreateObject: ERR - VxBSACreateObject: 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:52:57.646 [63217] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.428: errno: 2 2 0x00000002

07:52:57.646 [63217] <2> conf_update_time: ../../libvlibs/nbconf_glue.cpp.429: path: /home/oracle/bp.conf

07:52:57.646 [63217] <4> sbtend: INF - --- END of SESSION ---

07:52:57.646 [63217] <8> close_image: Session being terminated abnormally, cleaning up

07:52:57.646 [63217] <4> CleanUpShM: INF - dbclient waited 0 times for empty buffer, delayed 0 times

07:52:57.646 [63217] <16> CopyToShM: connection broken. Error #40

07:52:57.646 [63217] <16> writeToServer: ERR - CopyToShM() failed, no files backed up

07:52:57.646 [63217] <16> CleanUpShM: ERR - writeToServer() failed attempting to contact the server

07:52:57.646 [63217] <4> close_image: INF - backup FAILED

07:52:57.646 [63217] <4> close_image: INF ---- end of Backup ---

Thank you in Advance.

Naseer

[Shanli]

hi please share client RMAN log to check what happened. last 10-20 line of log is enough... located in : /oracle/admin/dba/bin/rman_logs/ if u couldnt find any logs, then ask your DBA team to enable it..

[manojhirway · Accepted solution]

From the log, it looks like a request to bprd was sent from the client. But bprd could not start the backup.

bprd log can also provide clues.