Forum Discussion

toichubek's avatar
toichubek
Level 3
14 years ago
Solved

error RMAN

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,

7.1.x and Earlier
Backup and Recovery
NetBackup
  • Will_Restore's avatar
    Will_Restore
    14 years ago

    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

  • Marianne's avatar
    Marianne
    Level 6
    14 years ago

    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's avatar
    toichubek
    Level 3
    14 years ago

    Marianne and wrobbins,

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

     

  • Marianne's avatar
    Marianne
    Level 6
    14 years ago

    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's avatar
    toichubek
    Level 3
    14 years ago

    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's avatar
    toichubek
    Level 3
    14 years ago

    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's avatar
    Marianne
    Level 6
    14 years ago

    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's avatar
    toichubek
    Level 3
    14 years ago

    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's avatar
    Marianne
    Level 6
    14 years ago

    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's avatar
    toichubek
    Level 3
    14 years ago

    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

  • toichubek's avatar
    toichubek
    Level 3
    14 years ago

    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