cancel
Showing results for 
Search instead for 
Did you mean: 

error RMAN

toichubek
Level 3
Partner Accredited

Hi all,

 

i have a netbackup media server 6.5 on Solaris 9, and get an error while backuping by rman,  here is some logs.

in Activity monitor, all the channels seems like ok, but the script gives:

 (6) the backup failed to back up the requested files

 

bptm logs:

 

15:49:36.847 [4617] <2> io_terminate_tape: writing empty backup header, drive index 12, copy 1
15:49:39.402 [4617] <2> io_terminate_tape: absolute block position prior to writing empty header is 18870022, copy 1
15:49:39.402 [4617] <2> io_terminate_tape: block position check: actual 18870022, expected 18870022
15:49:39.431 [4617] <2> process_tapealert: TapeAlert returned 0x00000000 0x00000000 (from io_terminate_tape)

 

rman error:

 Failed to process backup file <tomumunr_1_1>
ORA-19502: write error on file "tomumunr_1_1", blockno 6248961 (blocksize=512)
ORA-27030: skgfwrt: sbtwrite2 returned error
ORA-19511: Error received from media manager layer, error text:
   VxBSASendData: Failed with error:
channel ch01 disabled, job failed on it will be run on another channel
RMAN-03009: failure of backup command on ch02 channel at 12/20/2011 18:01:48
ORA-27192: skgfcls: sbtclose2 returned error - failed to close file
ORA-19511: Error received from media manager layer, error text:

 

 

PS: master server- Netbackup 7.1 on Red Hat

 

thanks in advance,

1 ACCEPTED SOLUTION

Accepted Solutions

Will_Restore
Level 6

17:41:37.642 [19541] <2> process_request: clnt = Geo-V890_2
17:41:37.642 [19541] <2> process_request: clnthostname = Geo-V890_2
17:41:37.642 [19541] <2> process_request: clnt_bp_conf_name = Geo-V890_2
17:41:37.642 [19541] <2> process_request: ccname = geo-v890_2
 

17:41:37.643 [19541] <2> bkarfiles:    client = Geo-V890_2
17:41:37.643 [19541] <2> bkarfiles:    client_hostname = geo-v890_2
 

 

make sure client_name in bp.conf, NetBackup policy and the RMAN script match (case-sensitive)

fix that and you should be good to go

View solution in original post

11 REPLIES 11

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

Is this a backup that worked fine before and started failing recently?

The bptm log is showing info/debug messages only <2> - no errors <16>.

The rman log does not reveal much either - just that the problem seems to be at NBU level. We are also missing the error text following this:

"Error received from media manager layer, error text:"

You need dbclient log on the client.

Create /usr/openv/netbackup/logs/dbclient folder, followed by:
chmod 777 /usr/openv/netbackup/logs/dbclient

Please post dbclient log as attachment after next failure.

We might need more NBU logs, depending on what dbclient log reveals.

toichubek
Level 3
Partner Accredited

rman logs:

ORA-19513: failed to identify sequential file
ORA-27206: requested file not found in media management catalog
continuing other job steps, job failed will not be re-run

toichubek
Level 3
Partner Accredited

Marianne,

 

no, this is new configured backup. i've sent rman logs again.

do i need to restart backup media server on that client after creation of folder?

 

PS:not installed client, installed media server.

 

thanks,

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

The media server is also the Oracle client?

No need to restart anything after creating dbclient log.

From the rest of rman log, there seems to be a comms problem between the master server and the client.

Please ensure that you have bprd log directory on the master. Restart is need after folder is created.

dbclient log on the client will tell us which Client_Name is sent to the master and if connection with the master succeeded.

bprd log on the master will tell us how client's incoming IP address is resolved to a hostname. This resolved hostname needs to correspond with Client name in Policy as well as Client_Name sent by Rman/dbclient.

toichubek
Level 3
Partner Accredited

The media server is also the Oracle client? Yes,

 

the problem is that, it takes an error at the end of the backup. it seems like, error occurs at last block.

Media server is on Solaris 9.

 

and there is another problem, this server connected to library with SAN, but speed is almost 150 MB/s. The other servers speed: 250-350MB/s

 

thanks,

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

You need logs to find out what's wrong with the Oracle backup.

Seems backup might have completed but verification in image catalog failed (my gut-feel is a name resolution...).

ALL of these logs are needed to troubleshoot:

On master: bprd, probably bpdbm as well (restart is needed after folders are created) 

On client: dbclient  (remember chmod 777 .....)

One problem per discussion, please! 99% of list members will envy transfer rate of 150 Mb/sec! If you really feel that this a problem, please start a new thread.

toichubek
Level 3
Partner Accredited

Here is dbclient log for 1 stream:

 

13:22:06.843 [19622] <2> int_FindBackupImage: INF - 0nmurkr2_1_1 not found
13:22:06.843 [19622] <2> xbsa_EndTransaction: INF - entering
13:22:06.843 [19622] <4> VxBSAEndTxn: INF - entering VxBSAEndTxn.
13:22:06.843 [19622] <4> VxBSAEndTxn: INF - Transaction being COMMITED.
13:22:06.843 [19622] <4> VxBSAGetEnv: INF - entering GetEnv - NBBSA_LOG_DIRECTORY
13:22:06.843 [19622] <4> VxBSAGetEnv: INF - returning - dbclient
13:22:06.843 [19622] <4> VxBSAEndTxn: INF - Cleaning directory: </usr/openv/netbackup/logs/dbclient>
13:22:06.843 [19622] <4> delete_old_files: entering delete_old_files.
13:22:06.843 [19622] <2> xbsa_EndTransaction: INF - leaving (0)

13:22:06.843 [19622] <2> int_FindBackupImage: INF - leaving
13:22:06.843 [19622] <2> int_SetImageInfoArray: INF - entering
13:22:06.843 [19622] <8> int_SetImageInfoArray: WRN - Backup file, 0nmurkr2_1_1, not found.
13:22:06.843 [19622] <2> int_SetImageInfoArray: INF - leaving
13:22:06.843 [19622] <2> int_GetImageInfo2: INF - leaving
13:22:06.843 [19622] <2> int_DumpSbtInfo: INF - entering
13:22:06.843 [19622] <2> int_DumpSbtInfo: INF - Media Information for Backup File : <0nmurkr2_1_1>
13:22:06.843 [19622] <2> int_DumpSbtInfo: INF - Unknown Type : <8>
13:22:06.843 [19622] <2> int_DumpSbtInfo: INF - leaving
13:22:06.843 [19622] <2> sbtinfo2: INF - leaving
13:22:06.844 [19622] <2> sbtremove2: INF - entering
13:22:06.844 [19622] <2> int_RemoveImage: INF - entering
13:22:06.844 [19622] <2> int_RemoveImage: INF - Removing backup image => <0nmurkr2_1_1>
13:22:06.844 [19622] <2> xbsa_ValidateFeatureId: INF - entering
13:22:06.844 [19622] <2> xbsa_ValidateFeatureId: INF - leaving (0)

13:22:07.028 [19622] <2> bsa_bplist: Request = ora10 dba Geo-V890_2 Geo-V890_2 Geo-V890_2 bo_cboss_sbt_oracle_full_vtl 5 cboss 3 999 1324027326 1324632126 4 4 1 1 1 0 4
 300 300 4 0 C C C C C 0 2 0 0 0
13:22:07.028 [19622] <4> bsa_bplist: Filepath = /0nmurkr2_1_1
13:22:07.188 [19622] <2> dbc_get_string: Output = EXIT STATUS 227
13:22:07.188 [19622] <4> bsa_bplist: entering bsa_bplist
13:22:07.190 [19622] <2> vnet_async_connect: vnet_vnetd.c.3983: connect in progress: 0 0x00000000
13:22:07.228 [19622] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
13:22:07.228 [19622] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bprd
13:22:07.282 [19623] <2> int_WriteData: INF - writing buffer # 196000 of size 262144
13:22:07.304 [19622] <2> vnet_async_connect: vnet_vnetd.c.4169: in progress connect: 0 0x00000000
13:22:07.304 [19622] <2> vnet_async_connect: vnet_vnetd.c.4172: connect: async CONNECT FROM 10.0.2.20.38560 TO 10.10.8.92.13724 fd = 17
13:22:07.304 [19622] <2> logconnections: BPRD CONNECT FROM 10.0.2.20.38560 TO 10.10.8.92.13724
13:22:07.304 [19622] <2> vauth_authentication_required: vauth_comm.c.749: no methods for address: no authentication required
13:22:07.305 [19622] <2> vauth_connector: vauth_comm.c.182: no methods for address: no authentication required
13:22:07.305 [19622] <2> bprd_connect: no authentication required
13:22:07.305 [19622] <2> vnet_dlopen_vxss_client_magic: vnet_vxss.c.1766: Assuming no VxSS for DB Agents: 0 0x00000000
13:22:07.305 [19622] <2> bsa_bplist: start_date = Fri Dec  9 13:22:06 2011

Marianne
Moderator
Moderator
Partner    VIP    Accredited Certified

It seems that dbclient is trying to verify backup image in master's image catalog.

As a start, check bprd log on master. Please post log as attachment if you need us to assist. bpdbm might also be needed.

Please also verify date and time on master and media/client? If there is a time difference, it should not be more than a couple of days.

toichubek
Level 3
Partner Accredited

here is logs from bprd:

media server - Geo-V890_2

master server - nbumedia

 

<2> process_request: user backup request = 329199 53 ora10 dba Geo-V890_2 Geo-V890_2 Geo-V890_2 /usr/openv/netbackup/logs/user_ops/dbext/logs/14989
.0.1324561496 bo_cboss_sbt_oracle_full_vtl NONE 5 cboss 0 4 0 C C C C C 0 0 0 0 5
17:41:37.642 [19541] <2> process_request: After V_sscanf of bufr
17:41:37.642 [19541] <2> process_request: clnt = Geo-V890_2
17:41:37.642 [19541] <2> process_request: clnthostname = Geo-V890_2
17:41:37.642 [19541] <2> process_request: clnt_bp_conf_name = Geo-V890_2
17:41:37.642 [19541] <2> process_request: keyword = cboss
17:41:37.642 [19541] <2> process_request: ccname = geo-v890_2
17:41:37.642 [19541] <2> get_type_of_client_port: db_getCLIENT() failed: no entity was found (227)
17:41:37.642 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: Geo-V890_2
17:41:37.642 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.642 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: localhost
17:41:37.642 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.642 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: Geo-V890_2
17:41:37.642 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.642 [19541] <2> init_cache: ../../libvlibs/vnet_hosts.c.968: 0: host_cache_size: 200 0x000000c8
17:41:37.642 [19541] <2> init_cache: ../../libvlibs/vnet_hosts.c.969: 0: cache_time: 3600 0x00000e10
17:41:37.643 [19541] <2> init_cache: ../../libvlibs/vnet_hosts.c.983: 0: host_failed_cache_size: 40 0x00000028
17:41:37.643 [19541] <2> init_cache: ../../libvlibs/vnet_hosts.c.984: 0: cache_time: 3600 0x00000e10
17:41:37.643 [19541] <2> process_request: After get_client_and_host_names
17:41:37.643 [19541] <2> process_request: clnt_bp_conf_name = Geo-V890_2
17:41:37.643 [19541] <2> process_request: target_clientname = Geo-V890_2
17:41:37.643 [19541] <2> process_request: target_hostname = Geo-V890_2
17:41:37.643 [19541] <2> process_request: retval = 0
17:41:37.643 [19541] <2> process_request: Before bkarfiles
17:41:37.643 [19541] <2> bkarfiles:    backup_or_archive = 1
17:41:37.643 [19541] <2> bkarfiles:    immediate_or_userdirected = 0
17:41:37.643 [19541] <2> bkarfiles:    client = Geo-V890_2
17:41:37.643 [19541] <2> bkarfiles:    client_hostname = geo-v890_2
17:41:37.643 [19541] <2> bkarfiles:    requesting_user = ora10
17:41:37.643 [19541] <2> bkarfiles:    requesting_group = dba
17:41:37.643 [19541] <2> bkarfiles:    progress_file = /usr/openv/netbackup/logs/user_ops/dbext/logs/14989.0.1324561496
17:41:37.643 [19541] <2> bkarfiles:    policy = bo_cboss_sbt_oracle_full_vtl
17:41:37.643 [19541] <2> bkarfiles:    sched = NONE
17:41:37.643 [19541] <2> bkarfiles:    keyword = cboss
17:41:37.643 [19541] <2> bkarfiles:    user_interface = 0
17:41:37.643 [19541] <2> bkarfiles:    monitor_backup_job = 0
17:41:37.643 [19541] <2> bkarfiles:    backup_jobidstr = NONE
17:41:37.643 [19541] <2> bkarfiles:    client_locales_present = 1
17:41:37.643 [19541] <2> bkarfiles:    bkup_lc_messages = C
17:41:37.643 [19541] <2> bkarfiles:    bkup_lc_time = C
17:41:37.643 [19541] <2> bkarfiles:    bkup_lc_ctype = C
17:41:37.643 [19541] <2> bkarfiles:    bkup_lc_collate = C
17:41:37.643 [19541] <2> bkarfiles:    bkup_lc_numeric = C
17:41:37.643 [19541] <2> bkarfiles:    bkup_with_non_rsvd_ports = 16974338
17:41:37.643 [19541] <2> bkarfiles:    client_type = 4
17:41:37.643 [19541] <2> bkarfiles:    cverbose = 5
17:41:37.643 [19541] <2> bkarfiles:    acknowledge_list = 0
17:41:37.643 [19541] <2> bkarfiles:    proxy_copy = 0
17:41:37.643 [19541] <2> bkarfiles:    generate_english_logs = 0
17:41:37.643 [19541] <2> bkarfiles:    sync_keep_alive = 0
17:41:37.643 [19541] <2> append_to_client_log: ../dbmisc.c.3300: about to call ConnectToBPCD connect_opts = 0x01030202
17:41:37.643 [19541] <2> ConnectToBPCD: db_getCLIENT(geo-v890_2) failed: 227
17:41:37.643 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: NULL
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: bpcd
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: localhost
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: geo-v890_2
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.644 [19541] <2> local_bpcr_connect: bpcr.c.276: connect_opts = 0x01030202 connect_opts2 = 0x01000100
17:41:37.644 [19541] <2> local_bpcr_connect: bpcr.c.283: connect_opts = 0x01000100
17:41:37.644 [19541] <2> local_bpcr_connect: bpcr.c.322: daemon_port_type = 0
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: geo-v890_2
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: localhost
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: geo-v890_2
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: geo-v890_2
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: veritas_pbx
17:41:37.644 [19541] <2> vnet_sortaddrs: ../../libvlibs/vnet_addrinfo.c.4026: 0: sorted addrs:: 1 0x00000001
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: 10.0.2.20
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: NULL
17:41:37.644 [19541] <2> get_pref_netconnection: ../../libvlibs/vnet_addrinfo.c.4882: 0: using interface : ANY
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: geo-v890_2
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: vnetd
17:41:37.644 [19541] <2> vnet_sortaddrs: ../../libvlibs/vnet_addrinfo.c.4026: 0: sorted addrs:: 1 0x00000001
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: 10.0.2.20
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.644 [19541] <2> get_pref_netconnection: ../../libvlibs/vnet_addrinfo.c.4882: 0: using interface : ANY
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1514: 0: found in file cache name: geo-v890_2
17:41:37.644 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1515: 0: found in file cache service: bpcd
17:41:37.645 [19541] <2> vnet_sortaddrs: ../../libvlibs/vnet_addrinfo.c.4026: 0: sorted addrs:: 1 0x00000001
17:41:37.645 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1370: 0: found in cache name: 10.0.2.20
17:41:37.645 [19541] <2> vnet_cached_getaddrinfo_and_update: ../../libvlibs/vnet_addrinfo.c.1371: 0: found in cache service: NULL
17:41:37.645 [19541] <2> get_pref_netconnection: ../../libvlibs/vnet_addrinfo.c.4882: 0: using interface : ANY
17:41:37.645 [19541] <2> vnet_async_connect: ../../libvlibs/vnet_connect.c.1200: 0: connect in progress: 1 0x00000001
17:41:37.646 [19541] <2> vnet_pbxConnect: ../../libvlibs/vnet_pbx.c.666: pbxSetAddrEx/pbxConnectEx return error 104:Connection reset by peer
17:41:37.646 [19541] <2> do_pbx_service: ../../libvlibs/vnet_connect.c.1718: 0: vnet_pbxConnect() failed: 18 0x00000012
17:41:37.646 [19541] <2> do_pbx_service: ../../libvlibs/vnet_connect.c.1719: 0: save_errno: 104 0x00000068
17:41:37.646 [19541] <2> do_pbx_service: ../../libvlibs/vnet_connect.c.1720: 0: use_vnetd: 0 0x00000000
17:41:37.646 [19541] <2> do_pbx_service: ../../libvlibs/vnet_connect.c.1721: 0: cr->vcr_service: bpcd
17:41:37.646 [19541] <2> vnet_async_connect: ../../libvlibs/vnet_connect.c.1353: 0: do_service failed: 18 0x00000012
17:41:37.646 [19541] <2> vnet_async_connect: ../../libvlibs/vnet_connect.c.1200: 0: connect in progress: 1 0x00000001
17:41:37.676 [19541] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.1957: 0: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006
17:41:37.676 [19541] <2> vnet_vnetd_service_socket: ../../libvlibs/vnet_vnetd.c.1971: 0: service: bpcd

Will_Restore
Level 6

17:41:37.642 [19541] <2> process_request: clnt = Geo-V890_2
17:41:37.642 [19541] <2> process_request: clnthostname = Geo-V890_2
17:41:37.642 [19541] <2> process_request: clnt_bp_conf_name = Geo-V890_2
17:41:37.642 [19541] <2> process_request: ccname = geo-v890_2
 

17:41:37.643 [19541] <2> bkarfiles:    client = Geo-V890_2
17:41:37.643 [19541] <2> bkarfiles:    client_hostname = geo-v890_2
 

 

make sure client_name in bp.conf, NetBackup policy and the RMAN script match (case-sensitive)

fix that and you should be good to go

toichubek
Level 3
Partner Accredited

Marianne and wrobbins,

thanks for your help. i've changed client name in policy. i forget about case sensitive :)