Forum Discussion

woland255's avatar
woland255
Level 2
6 years ago

Problem during restoring MaxDB backup for SAP

Hi,

I am trying to restore MAXDB backup with netbackup 7.6.

bsi.env:

BACKINT /usr/openv/netbackup/bin/backint
OUTPUT /sapdb/data/wrk/backint_dir/backint.in
OUTPUT /sapdb/data/wrk/backint_dir/backint.out
ERROROUTPUT /sapdb/data/wrk/backint_dir/backint.err
PARAMETERFILE /sapdb/data/wrk/backint_dir/initSAP.utl

initSAP.utl:

switch_list /sapdb/data/wrk/.switch.lis
switch_sem /sapdb/data/wrk/.switch.sem
switch_log /sapdb/data/wrk/.switch.log
backint_dir /sapdb/data/wrk/backint_dir
server <serveraddr>
client <clientaddr>
drives 1
policy sapdb-DB-REMOTE-TAPE
schedule Default-Application-Backup

Policy is active and NB client sees backup files:

[root@client backint_dir]# /usr/openv/netbackup/bin/bplist -C <clientaddr> -t 17 -l -R /
-rw-rw---- sdb       sdba           684181 Sep 17 22:27 /storage/sapdb/data/wrk/SDB/dbm.ebf
-rw-rw---- sdb       sdba          1283690 Sep 17 22:27 /storage/sapdb/data/wrk/SDB/dbm.knl
-rw------- sdb       sdb        712838144K Sep 17 16:37 /sapdb/data/wrk/backdata
-rw-rw---- sdb       sdba           683671 Sep 15 18:31 /storage/sapdb/data/wrk/SDB/dbm.ebf
-rw-rw---- sdb       sdba          1282841 Sep 15 18:31 /storage/sapdb/data/wrk/SDB/dbm.knl
-rw------- sdb       sdb        712856064K Sep 15 11:00 /sapdb/data/wrk/backdata
-rw-rw---- sdb       sdba           682311 Sep 08 18:15 /storage/sapdb/data/wrk/SDB/dbm.ebf
-rw-rw---- sdb       sdba          1280577 Sep 08 18:15 /storage/sapdb/data/wrk/SDB/dbm.knl
-rw------- sdb       sdb        712764416K Sep 08 11:00 /sapdb/data/wrk/backdata
-rw-rw---- sdb       sdba           680951 Sep 01 18:16 /storage/sapdb/data/wrk/SDB/dbm.ebf
-rw-rw---- sdb       sdba          1278313 Sep 01 18:16 /storage/sapdb/data/wrk/SDB/dbm.knl
-rw------- sdb       sdb        712537088K Sep 01 11:00 /sapdb/data/wrk/backdata
-rw-rw---- sdb       sdba           680101 Aug 28 09:03 /storage/sapdb/data/wrk/SDB/dbm.ebf
-rw-rw---- sdb       sdba          1276898 Aug 28 07:47 /storage/sapdb/data/wrk/SDB/dbm.knl
-rw------- sdb       sdb         349765632 Aug 28 09:00 /sapdb/data/wrk/backlog
-rw-rw---- sdb       sdba           648949 Jun 29 14:36 /storage/sapdb/data/wrk/SDB/dbm.ebf
-rw-rw---- sdb       sdba          1223694 Jun 29 14:36 /storage/sapdb/data/wrk/SDB/dbm.knl
-rw------- sdb       sdb        670006784K Jun 29 09:45 /sapdb/data/wrk/backdata

But.... If I try to start restore or check backup, after timeout it fails with:
 backup operation was unsuccessful The backup tool failed with 2 as sum of exit codes. The database request was canceled and ended with error -903.

bsi.ebp:

2018-09-26 14:37:24
Setting environment variable 'TEMP' for the directory for temporary files and pipes to default ''.
Setting environment variable 'TMP' for the directory for temporary files and pipes to default ''.
Using connection to Backint for MaxDB Interface.

2018-09-26 14:37:24
Checking existence and configuration of Backint for MaxDB.
    Reading the Backint for MaxDB configuration file '/sapdb/data/wrk/SDB/bsi.env'.
        Found keyword 'BACKINT' with value '/usr/openv/netbackup/bin/backint'.
        Found keyword 'OUTPUT' with value '/sapdb/data/wrk/backint_dir/backint.in'.
        Found keyword 'OUTPUT' with value '/sapdb/data/wrk/backint_dir/backint.out'.
        Found keyword 'ERROROUTPUT' with value '/sapdb/data/wrk/backint_dir/backint.err'.
        Found keyword 'PARAMETERFILE' with value '/sapdb/data/wrk/backint_dir/initSAP.utl'.
    Finished reading of the Backint for MaxDB configuration file.

    Using '/usr/openv/netbackup/bin/backint' as Backint for MaxDB program.
    Using '/sapdb/data/wrk/SDB/bsi.in' as input file for Backint for MaxDB.
    Using '/sapdb/data/wrk/backint_dir/backint.out' as output file for Backint for MaxDB.
    Using '/sapdb/data/wrk/backint_dir/backint.err' as error output file for Backint for MaxDB.
    Using '/sapdb/data/wrk/backint_dir/initSAP.utl' as parameter file for Backint for MaxDB.
    Using '300' seconds as timeout for Backint for MaxDB in the case of success.
    Using '300' seconds as timeout for Backint for MaxDB in the case of failure.
    Using '/sapdb/data/wrk/SDB/dbm.knl' as backup history of a database to migrate.
    Using '/sapdb/data/wrk/SDB/dbm.ebf' as external backup history of a database to migrate.
    Checking availability of backups using backint's inquire function.
Check passed successful.

2018-09-26 14:37:24
Checking medium.
Check passed successfully.

2018-09-26 14:37:24
Preparing restore.
    Setting environment variable 'BI_CALLER' to value 'DBMSRV'.
    Setting environment variable 'BI_REQUEST' to value 'NEW'.
    Setting environment variable 'BI_BACKUP' to value 'FULL'.
    Got the following list of external backup ID's:
        "SDB VXP11537140637 /sapdb/data/wrk/backdata"

    Constructed Backint for MaxDB call '/usr/openv/netbackup/bin/backint -u SDB -f restore -t file -p /sapdb/data/wrk/backint_dir/initSAP.utl -i /sapdb/data/wrk/SDB/bsi.in -c'.
    Created temporary file '/sapdb/data/wrk/backint_dir/backint.out' as output for Backint for MaxDB.
    Created temporary file '/sapdb/data/wrk/backint_dir/backint.err' as error output for Backint for MaxDB.
    Writing 'VXP11537140637 /sapdb/data/wrk/backdata' to the input file.
Prepare passed successfully.

2018-09-26 14:37:24
Creating pipes for data transfer.
    Creating pipe '/sapdb/data/wrk/backdata' ... Done.
All data transfer pipes have been created.

2018-09-26 14:37:24
Starting database action for the restore.
    Requesting 'RESTORE DATA FROM '/sapdb/data/wrk/backdata' PIPE  BLOCKSIZE 64 MEDIANAME 'BACKData'' from db-kernel.
The database is working on the request.

2018-09-26 14:37:24
Waiting until database has prepared the restore.
    Asking for state of database.
    2018-09-26 14:37:42 Database has finished preparation of the restore.
The database has prepared the restore successfully.

2018-09-26 14:37:42
Starting Backint for MaxDB.
    Starting Backint for MaxDB process '/usr/openv/netbackup/bin/backint -u SDB -f restore -t file -p /sapdb/data/wrk/backint_dir/initSAP.utl -i /sapdb/data/wrk/SDB/bsi.in -c >>/sapdb/data/wrk/backint_dir/backint.out 2>>/sapdb/data/wrk/backint_dir/backint.err'.
    Process was started successfully.
Backint for MaxDB has been started successfully.

2018-09-26 14:37:42
Waiting for end of the restore operation.
    2018-09-26 14:37:42 The backup tool is running.
    2018-09-26 14:37:42 The database is working on the request.

    2018-09-26 14:37:47 The backup tool is running.
    2018-09-26 14:37:47 The database is working on the request.

    2018-09-26 14:37:49 The backup tool process has finished work with return code 2.

    2018-09-26 14:37:52 The database is working on the request.

    2018-09-26 14:38:02 The database is working on the request.

    2018-09-26 14:38:17 The database is working on the request.

    2018-09-26 14:38:37 The database is working on the request.

    2018-09-26 14:38:50 Canceling Utility-task after a timeout of 60 seconds elapsed ... OK.

    2018-09-26 14:38:51 The database has finished work on the request.
    Receiving a reply from the database kernel.
    Got the following reply from db-kernel:
        SQL-Code              :-903
The restore operation has ended.

2018-09-26 14:38:51
Filling reply buffer.
    Have encountered error -24920:
        The backup tool failed with 2 as sum of exit codes. The database request was canceled and ended with error -903.

    Constructed the following reply:
        ERR
        -24920,ERR_BACKUPOP: backup operation was unsuccessful
        The backup tool failed with 2 as sum of exit codes. The database request was canceled and ended with error -903.
Reply buffer filled.

2018-09-26 14:38:51
Cleaning up.
    Removing data transfer pipes.
        Removing data transfer pipe /sapdb/data/wrk/backdata ... Done.
    Removed data transfer pipes successfully.

    Copying output of Backint for MaxDB to this file.
    ---------- Begin of output of Backint for MaxDB (/sapdb/data/wrk/backint_dir/backint.out)----------
        ********************************************************************************
        Program:                /usr/openv/netbackup/bin/backint 7.6
        Input File:             /sapdb/data/wrk/SDB/bsi.in
        Profile:                /sapdb/data/wrk/backint_dir/initSAP.utl
        Function:               RESTORE
        ********************************************************************************
        ********************************************************************************
        ********************************************************************************

    ---------- End of output of Backint for MaxDB (/sapdb/data/wrk/backint_dir/backint.out)----------
    Removed Backint for MaxDB's temporary output file '/sapdb/data/wrk/backint_dir/backint.out'.
    Copying error output of Backint for MaxDB to this file.
    ---------- Begin of error output of Backint for MaxDB (/sapdb/data/wrk/backint_dir/backint.err)----------

    ---------- End of error output of Backint for MaxDB (/sapdb/data/wrk/backint_dir/backint.err)----------
    Removed Backint for MaxDB's temporary error output file '/sapdb/data/wrk/backint_dir/backint.err'.
    Removed the Backint for MaxDB input file '/sapdb/data/wrk/SDB/bsi.in'.
Have finished clean up successfully.


And in log of netbacku's backint I can see following:

14:15:03.068 [9002] <2> backint_get_param: -i argv: </sapdb/data/wrk/SDB/bsi.in>
14:15:03.076 [9002] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:15:03.076 [9002] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.54770 TO 192.168.80.80.1556 fd = 9
14:15:03.682 [9002] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:15:03.682 [9002] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.59049 TO 192.168.80.80.1556 fd = 9
14:15:04.212 [9002] <16> open_file_list: Opening input file: </sapdb/data/wrk/SDB/bsi.in>
14:15:04.213 [9002] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************
14:15:04.213 [9002] <4> /usr/openv/netbackup/bin/backint 7.6: Program:          /usr/openv/netbackup/bin/backint 7.6
14:15:04.213 [9002] <4> /usr/openv/netbackup/bin/backint 7.6: Input File:               /sapdb/data/wrk/SDB/bsi.in
14:15:04.213 [9002] <4> /usr/openv/netbackup/bin/backint 7.6: Profile:          /sapdb/data/wrk/backint_dir/initSAP.utl
14:15:04.213 [9002] <4> /usr/openv/netbackup/bin/backint 7.6: Function:         INQUIRE
14:15:04.213 [9002] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************
14:15:04.213 [9002] <4> read_input_file: Entering.
14:15:04.213 [9002] <4> read_inquire_input_file: line: <VXP11537140637 /sapdb/data/wrk/backdata
>
14:15:04.213 [9002] <4> read_inquire_input_file: objectID: <VXP11537140637> objectName: </sapdb/data/wrk/backdata>
14:15:04.213 [9002] <4> read_inquire_input_file: line: <VXP11537054238 /sapdb/data/wrk/backdata

............................ many lines of such enties with different backupIDs..................

14:15:04.240 [9002] <4> read_inquire_input_file: objectID: <VXP11372254270> objectName: </sapdb/data/wrk/backdata>
14:15:04.248 [9002] <4> read_input_file: Exiting.
14:15:04.251 [9002] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:15:04.251 [9002] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.55984 TO 192.168.80.80.1556 fd = 10
14:15:04.783 [9002] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:15:04.783 [9002] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.43062 TO 192.168.80.80.1556 fd = 10
14:15:05.518 [9002] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:15:05.518 [9002] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.52521 TO 192.168.80.80.1556 fd = 10
14:15:06.375 [9002] <4> VxBSAQueryObject: INF - No match was found for query
14:15:06.375 [9002] <4> do_fifo_inquire: No object matched the specified predicate.
14:15:06.375 [9002] <4> do_fifo_inquire: #NOTFOUND /sapdb/data/wrk/backdata
14:15:06.375 [9002] <4> do_fifo_inquire: #NOTFOUND /sapdb/data/wrk/backdata

................................... many lines...............................................................................................

14:36:55.295 [9850] <4> do_fifo_inquire: No object matched the specified predicate.
14:36:55.295 [9850] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************
14:37:42.262 [9918] <2> backint_get_param: -i argv: </sapdb/data/wrk/SDB/bsi.in>
14:37:42.271 [9918] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:37:42.271 [9918] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.50726 TO 192.168.80.80.1556 fd = 9
14:37:42.800 [9918] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:37:42.800 [9918] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.56937 TO 192.168.80.80.1556 fd = 9
14:37:43.340 [9918] <16> open_file_list: Opening input file: </sapdb/data/wrk/SDB/bsi.in>
14:37:43.340 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************
14:37:43.340 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: Program:          /usr/openv/netbackup/bin/backint 7.6
14:37:43.340 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: Input File:               /sapdb/data/wrk/SDB/bsi.in
14:37:43.340 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: Profile:          /sapdb/data/wrk/backint_dir/initSAP.utl
14:37:43.340 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: Function:         RESTORE
14:37:43.340 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************
14:37:43.340 [9918] <4> read_input_file: Entering.
14:37:43.340 [9918] <4> read_inquire_input_file: line: <VXP11537140637 /sapdb/data/wrk/backdata
>
14:37:43.340 [9918] <4> read_inquire_input_file: objectID: <VXP11537140637> objectName: </sapdb/data/wrk/backdata>
14:37:43.340 [9918] <4> read_input_file: Exiting.
14:37:43.340 [9921] <4> get_client_read_timeout: Enter.
14:37:43.340 [9921] <4> verifyFifoExist: Enter.
14:37:43.340 [9918] <2> do_fifo_restore: Started child process <9921>
14:37:43.340 [9918] <2> sap_Wait: Start waiting.
14:37:43.343 [9921] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:37:43.343 [9921] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.59110 TO 192.168.80.80.1556 fd = 10
14:37:43.875 [9921] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:37:43.875 [9921] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.47946 TO 192.168.80.80.1556 fd = 10
14:37:44.601 [9921] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:37:44.601 [9921] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.43282 TO 192.168.80.80.1556 fd = 10
14:37:45.351 [9921] <2> vnet_pbxConnect: pbxConnectEx Succeeded
14:37:45.351 [9921] <2> logconnections: BPRD CONNECT FROM 192.168.80.9.38460 TO 192.168.80.80.1556 fd = 10
14:37:46.197 [9921] <4> VxBSAQueryObject: INF - No match was found for query
14:37:46.197 [9921] <4> restore_one_fifo: No object matched the specified predicate.
14:37:46.197 [9921] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************
14:37:48.341 [9918] <16> sap_Wait: ERR - job (9921) failed status (2)
14:37:48.341 [9918] <4> /usr/openv/netbackup/bin/backint 7.6: ********************************************************************************

bsi.in for this case was:

VXP11537140637 /sapdb/data/wrk/backdata

So it seems that backint can't find file in backup.

Can you suggest why this happens

Thanks a alot


6 Replies

  • Hello,

    check the backups availability with dbmcli:

    dbmcli -d <DBNAME> -u <USER>,<PSW>

    dbmcli> backup_ext_ids_get BACKdata <DBNAME>

    dbmcli> backup_ext_ids_list[next]

    then you should get something like this:

    AVAILABLE|MAXDB VXP11444287599 \\.\PIPE\medium1|DATA  MIGRATION|2015-10-08 08:59:43|

    Do you see them as Available?

    Regards

    Michal

     

    • woland255's avatar
      woland255
      Level 2

      Hi, Michal

      ./dbmcli on SDB> backup_ext_ids_get BACKdata SDB
      OK

      There are no ext itd's in this output.

      But:

       

      ./dbmcli on SDB>backup_history_list -e -r last
      OK
      END
      5B9EE77B01A7|DAT_000001287|SAVE WARM|2018-09-17 02:30:03|2018-09-17 02:30:03|2018-09-17 02:30:28|2018-09-17 08:08:55| 159785099|          |NO |BACKData                                                        |  89104576|         1|         0|                                                                                                |
      E:UNAVAILABLE|SDB VXP11537140637 /sapdb/data/wrk/backdata|

      So, they are not seen as available, correct? And why it could be so?

      Thanks a lot.

      • Michal_Mikulik1's avatar
        Michal_Mikulik1
        Moderator

        Hello,

        one note to backup_ext_ids_get  - it displays only OK, it must be followed by backup_ext_ids_list to display id's availability.

        But ok when they are unavailable, then doublecheck that BSI_ENV is set to the correct file, with intended initSAP.utl with the proper policy name.

        dbmcli -d MAXDB -u <user/,psw> dbm_configset -raw BSI_ENV …\bsi*.env

        and this policy must be active (you mentioned it is).

        If it is a redirected restore (not in place restore), also client name must be set in initSAP.utl.

        Regards

        Michal