Informix

 View Only

  • 1.  Informix restore failure with "Unable to close the storage space restore"

    Posted Wed May 03, 2023 09:26 AM

    Hello Community,
    Bit new to Informix and to the group so pardon me if missed anything basic.

    I am trying to restore Informix instance with the command "onbar -r -p" which should perform a physical restore of dbspaces.
    The restore is failing with "Unable to close the storage space restore" error. All restore data is transferred correctly for the dbspace with BSAGetData calls and the error occurs after BSAEndTxn. Looks like it is not able to commit the restored data?

    ----- bar_act.log -----
     2023-05-03 15:56:05 1365655  1365653 Working with cvsm as generic storage manager.
     2023-05-03 15:56:05 1365655  1365653 Successfully connected to Storage Manager.
     2023-05-03 15:56:07 1365655  1365653 Begin reserved pages read (level 0 of rootdbs, Storage Manager copy ID: 1683103262 1362033).
     2023-05-03 15:56:07 1365655  1365653 Completed reserved pages read (level 0 of rootdbs).
     2023-05-03 15:56:12 1365655  1365653 Successfully connected to Storage Manager.
     2023-05-03 15:56:13 1365655  1365653 Begin reserved pages read (level 0 of rootdbs, Storage Manager copy ID: 1683103262 1362033).
     2023-05-03 15:56:13 1365655  1365653 Completed reserved pages read (level 0 of rootdbs).
     2023-05-03 15:56:13 1365655  1365653 Successfully connected to Storage Manager.
     2023-05-03 15:56:15 1365655  1365653 Begin cold level 0 restore rootdbs (Storage Manager copy ID: 1683103262 1362033).
     2023-05-03 15:56:26 1365655  1365653 Unable to close the storage space restore: buc_fe.c : Archive API processing failed at line 684 for msgtype.
     2023-05-03 15:56:31 1365655  1365653 (-43140) Due to the previous error, logical restore will not be attempted.
     2023-05-03 15:56:31 1365655  1365653 /opt/Informix_Software_Bundle/bin/onbar_d complete, returning 131 (0x83)

    ----- bar_dbug.log -----
     2023-05-03 15:56:24 1365655  1365653 do_phys_restore: calling bar_phys_write_restore(buf 0x0x7ffc44d51bb8, bufnbytes 63488, events, errtxt)
     2023-05-03 15:56:24 1365655  1365653 bar_phys_write_restore: enter
     2023-05-03 15:56:24 1365655  1365653 bar_phys_write_restore: input buf 0xacbed400 bufnbytes 63488
     2023-05-03 15:56:24 1365655  1365653 bar_phys_write_restore: output buf 0xacbfd400 events 0 errtxt
     2023-05-03 15:56:24 1365655  1365653 bar_phys_write_restore: return 0 (0x00)
     2023-05-03 15:56:24 1365655  1365653 do_phys_restore: Got 0:7378 pages for rootdbs
     2023-05-03 15:56:24 1365655  1365653 barEndTxn: enter
     2023-05-03 15:56:24 1365655  1365653 BSAEndData: enter
     2023-05-03 15:56:24 1365655  1365653 bar_alarm: enter
     2023-05-03 15:56:24 1365655  1365653 bar_alarm: input 240 seconds
     2023-05-03 15:56:24 1365655  1365653 bar_alarm: return 240 (0xf0)
     2023-05-03 15:56:24 1365655  1365653 BSAEndData: return 0 (0x00)
     2023-05-03 15:56:24 1365655  1365653 BSAEndTxn: enter
     2023-05-03 15:56:24 1365655  1365653 bar_alarm: enter
     2023-05-03 15:56:24 1365655  1365653 bar_alarm: input 240 seconds
     2023-05-03 15:56:24 1365655  1365653 bar_alarm: return 240 (0xf0)
     2023-05-03 15:56:24 1365655  1365653 BSAEndTxn: return 0 (0x00)
     2023-05-03 15:56:24 1365655  1365653 bar_upd_bootfile: enter
     2023-05-03 15:56:24 1365655  1365653 bar_upd_bootfile: input: bar_objdesc
         obj_id 0 obj_name 'rootdbs' obj_type 'R' act_id 0 act_type 2 act_status 0
         act_start '2023-05-03 15:56:15'  act_end '2023-05-03 15:56:24'
         ins_time 0 rsam_time 278678 seal_time 1683103233 prev_seal_time 1683026781 level 0 copyid hi:lo 1683103262:1362033 req_act_id 12
         logstream 0 est_pages hi:lo 0:0 first_log 11 chpt_log 11 last_log 0
         partial_flag 0 do_query 0 ins_sm_id 0 ins_sm_name ''
         ins_verify 0 ins_verify_date '' restore order 0:278678
         objInfo ''
         retry 0 in_catalog 1 in_bootfile 0 child_pid 15539634058559488 child_state 1
         bkup_host '' backup_order 7
     2023-05-03 15:56:24 1365655  1365653 bar_upd_bootfile: return 0 (0x00)
     2023-05-03 15:56:24 1365655  1365653 barEndTxn: return 0 (0x00)
     2023-05-03 15:56:24 1365655  1365653 do_phys_restore: calling bar_phys_close_restore commit_fl
     2023-05-03 15:56:24 1365655  1365653 bar_phys_close_restore: enter
     2023-05-03 15:56:24 1365655  1365653 bar_phys_close_restore: input commit_flag 0
     2023-05-03 15:56:26 1365655  1365653 bar_phys_close_restore: output errtxt buc_fe.c : Archive API processing failed at line 684 for msgtype
     2023-05-03 15:56:26 1365655  1365653 bar_phys_close_restore: return 130 (0x82)
     2023-05-03 15:56:26 1365655  1365653 do_phys_restore: return 131 (0x83)
     2023-05-03 15:56:31 1365655  1365653 return from bar_exec 131
     2023-05-03 15:56:31 1365655  1365653 bar_unloadXBSA: enter
     2023-05-03 15:56:31 1365655  1365653 bar_unloadXBSA: return 0 (0x00)
     2023-05-03 15:56:31 1365655  1365653 bar_main: return 131 (0x83)
     2023-05-03 15:56:31 1365655  1365653 bar_main complete, returning 131 (0x83)

    Please let me know if I missed adding any information. I have no clue why restore is failing. I don't see anything helpful in online log either.
    To verify if the backup image is valid, I already tried onbar -v and it is successful.

    2023-05-02 18:17:13 1324621  1324619 /opt/Informix_Software_Bundle/bin/onbar_d -v
    2023-05-02 18:17:14 1324621  1324619 Working with cvsm as generic storage manager.
    2023-05-02 18:17:44 1324621  1324619 Successfully connected to Storage Manager.
    2023-05-02 18:17:46 1324621  1324619 Begin backup verification of level 0 for rootdbs (Storage Manager copy ID: 1683026766 1321872).
    2023-05-02 18:17:49 1324621  1324619 Begin backup verification of level 0 for logdbs (Storage Manager copy ID: 1683026771 1321872).
    2023-05-02 18:17:50 1324621  1324619 Begin backup verification of level 0 for physdbs (Storage Manager copy ID: 1683026771 1321872).
    2023-05-02 18:17:51 1324621  1324619 Begin backup verification of level 0 for datadbs (Storage Manager copy ID: 1683026771 1321872).
    2023-05-02 18:17:52 1324621  1324619 Begin backup verification of level 0 for sbspace (Storage Manager copy ID: 1683026771 1321872).
    2023-05-02 18:17:54 1324621  1324619 Completed level 0 backup verification successfully.
    2023-05-02 18:17:54 1324621  1324619 Successfully connected to Storage Manager.
    2023-05-02 18:17:54 1324621  1324619 /opt/Informix_Software_Bundle/bin/onbar_d complete, returning 0 (0x00)

    Thanks much for any helpful advice/clue.




  • 2.  RE: Informix restore failure with "Unable to close the storage space restore"

    IBM Champion
    Posted Wed May 03, 2023 09:31 AM

    Abhishek:

    In general it is helpful to post your platform (hardware and OS type and version as well as Informix version), but in this case, unless your system is quite old, I would open a PMR with IBM to track this. It is not an error that I have seen before, unless others have?

    Art



    ------------------------------
    Art S. Kagel, President and Principal Consultant
    ASK Database Management Corp.
    www.askdbmgt.com
    ------------------------------

    Original Message


  • 3.  RE: Informix restore failure with "Unable to close the storage space restore"

    Posted Wed May 03, 2023 03:34 PM

    Thanks for the headsup! I will keep a note to share the details.
    For now, this is a CentOS 8 VM with Informix version 12.10

    I was thinking of opening a PMR but thought of giving this discussion a try if someone might have faced this before.
    Will check with IBM support on this.



    ------------------------------
    Abhishek
    ------------------------------

    Original Message


  • 4.  RE: Informix restore failure with "Unable to close the storage space restore"

    IBM Champion
    Posted Wed May 03, 2023 09:57 AM

    Are there any messages on the commvault server indicating an issue?

    Just to confirm - was the backup taken on the same server that you are restoring to, i.e. not a redirected restore?

    I did run into problems with onbar restores of instances on 12.10.FC8, but the message is different and the problem had something to do with many chunks, which I don't think that you have.





    ------------------------------
    Mike Walker
    xDB Systems, Inc
    www.xdbsystems.com
    ------------------------------

    Original Message


  • 5.  RE: Informix restore failure with "Unable to close the storage space restore"

    Posted Wed May 03, 2023 03:39 PM

    No issues on Commvault side. Restore buffers are being sent correctly and the error seems to be coming after restore session is complete and data needs to be committed to disk. To answer your query, yes it is in-place restore to the same machine.



    ------------------------------
    Abhishek
    ------------------------------

    Original Message


  • 6.  RE: Informix restore failure with "Unable to close the storage space restore"

    IBM Champion
    Posted Wed May 03, 2023 04:05 PM

    HI,

    Try increaseing BAR_DEBUG to 6 and send us the output.

    Regards,

    David.



    ------------------------------
    David Williams
    ------------------------------

    Original Message


  • 7.  RE: Informix restore failure with "Unable to close the storage space restore"

    Posted Thu May 04, 2023 02:16 AM

    Hi
    Try verifying that the data can be restored using onbar -r -v
    Note that this might vary depending of type of backup system used as backend, where some might just report if media exists.
    I dont remember how this is done in Informix, but might give some hints.

    Regards Tomas
    CEO Spictera
    https://www.spictera.com



    ------------------------------
    Tomas Dalebjörk
    ------------------------------

    Original Message