File Level Restore Issue



  • Hi.

    On version 5.6.1

    I do a simple (full) backup,and maintain 4 delta backups. This is on a Windows 10 VM.

    The first delta (based on time) can be read with no problem. The other three are coming up with the following error:

    "stack": "Error: Command failed: mount --options=loop,ro --source=/tmp/tmp-817LUwT6p8Fv0jk/vhdi2 --target=/tmp/tmp-817my7grl9O3GlI
    mount: wrong fs type, bad option, bad superblock on /dev/loop0,
           missing codepage or helper program, or other error
    

    So say we have this...
    8AM
    9AM
    10AM
    11AM

    The 8AM can be restored from, the other three cannot.

    The next hour, when 9AM is the oldest delta, IT can now be read from.

    Any thoughts?



  • This looks like the error we initially ran into when this feature was originally implemented. Can you post the output of vhdimount -V?



  • @Danp said:

    This looks like the error we initially ran into when this feature was originally implemented. Can you post the output of vhdimount -V?

    vhdimount 20160108

    Copyright (C) 2012-2016, Joachim Metz.
    This is free software; see the source for copying conditions. There is NO
    warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
    Report bugs to joachim.metz@gmail.com.



  • @BRRABill That's an issue. You want the later version (20160424).



  • @Danp said:

    @BRRABill That's an issue. You want the later version (20160424).

    It says mine is the current version. How do I update it?



  • @Danp said:

    20160424

    I am on 16.04 ... might that make a difference? (All my Googling seems to have the version of vhdimount you suggested running on 16.10)



  • @BRRABill Yes. I'm on 16.10. I believe I was previously on 16.04 when I ran into the issue. Had to upgrade to get the correct library version.



  • @Danp said:

    @BRRABill Yes. I'm on 16.10. I believe I was previously on 16.04 when I ran into the issue. Had to upgrade to get the correct library version.

    I will upgrade and see if that issue goes away.



  • Upgrading to 16.10 did indeed fix that issue.

    However, I am now getting errors on other VMs

    "message": "Command failed: vgchange -ay graylog-vg
    File descriptor 11 (/var/lib/xo-server/data/leveldb/LOG) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    File descriptor 12 (/var/lib/xo-server/data/leveldb/LOCK) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    File descriptor 13 (/var/lib/xo-server/data/leveldb/000086.log) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    File descriptor 15 (/var/lib/xo-server/data/leveldb/MANIFEST-000084) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    Volume group "graylog-vg" not found
    Cannot process volume group graylog-vg



  • Strangely enough I ran another delta backup and that one worked.

    Strange...



  • And just to make things even stranger, now ALLLLLL of them work since I took the one new Delta backup.



  • @BRRABill said:

    Upgrading to 16.10 did indeed fix that issue.

    However, I am now getting errors on other VMs

    "message": "Command failed: vgchange -ay graylog-vg
    File descriptor 11 (/var/lib/xo-server/data/leveldb/LOG) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    File descriptor 12 (/var/lib/xo-server/data/leveldb/LOCK) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    File descriptor 13 (/var/lib/xo-server/data/leveldb/000086.log) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    File descriptor 15 (/var/lib/xo-server/data/leveldb/MANIFEST-000084) leaked on vgchange invocation. Parent PID 862: /usr/local/bin/node
    Volume group "graylog-vg" not found
    Cannot process volume group graylog-vg

    FWIW, I'm seeing similar errors.



  • Also seeing this --

    Feb 01 14:13:50 xo-5 xo-server[15394]: { Error: Command failed: mount --options=loop,ro --source=/dev/centos/root --target=/tmp/tmp-15394LhJ5uBDdCp5K
    Feb 01 14:13:50 xo-5 xo-server[15394]: mount: cannot mount /dev/loop1 read-only
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise.all.then.arr (/opt/xo-server/node_modules/execa/index.js:201:11)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at tryCatcher (/opt/xo-server/node_modules/bluebird/js/release/util.js:16:23)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromiseFromHandler (/opt/xo-server/node_modules/bluebird/js/release/promise.js:510:31)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromise (/opt/xo-server/node_modules/bluebird/js/release/promise.js:567:18)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromise0 (/opt/xo-server/node_modules/bluebird/js/release/promise.js:612:10)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromises (/opt/xo-server/node_modules/bluebird/js/release/promise.js:691:18)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._fulfill (/opt/xo-server/node_modules/bluebird/js/release/promise.js:636:18)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at PromiseArray._resolve (/opt/xo-server/node_modules/bluebird/js/release/promise_array.js:125:19)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at PromiseArray._promiseFulfilled (/opt/xo-server/node_modules/bluebird/js/release/promise_array.js:143:14)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromise (/opt/xo-server/node_modules/bluebird/js/release/promise.js:572:26)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromise0 (/opt/xo-server/node_modules/bluebird/js/release/promise.js:612:10)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Promise._settlePromises (/opt/xo-server/node_modules/bluebird/js/release/promise.js:691:18)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Async._drainQueue (/opt/xo-server/node_modules/bluebird/js/release/async.js:133:16)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Async._drainQueues (/opt/xo-server/node_modules/bluebird/js/release/async.js:143:10)
    Feb 01 14:13:50 xo-5 xo-server[15394]:     at Immediate.Async.drainQueues (/opt/xo-server/node_modules/bluebird/js/release/async.js:17:14)
    Feb 01 14:13:50 xo-5 xo-server[15394]:   code: 32,
    Feb 01 14:13:50 xo-5 xo-server[15394]:   killed: false,
    Feb 01 14:13:50 xo-5 xo-server[15394]:   stdout: '',
    Feb 01 14:13:50 xo-5 xo-server[15394]:   stderr: 'mount: cannot mount /dev/loop1 read-only\n',
    Feb 01 14:13:50 xo-5 xo-server[15394]:   failed: true,
    Feb 01 14:13:50 xo-5 xo-server[15394]:   signal: null,
    Feb 01 14:13:50 xo-5 xo-server[15394]:   cmd: 'mount --options=loop,ro --source=/dev/centos/root --target=/tmp/tmp-15394LhJ5uBDdCp5K',
    Feb 01 14:13:50 xo-5 xo-server[15394]:   timedOut: false }
    Feb 01 14:13:51 xo-5 xo-server[15394]: Wed, 01 Feb 2017 20:13:51 GMT xo:perf blocked for 23ms
    Feb 01 14:13:51 xo-5 xo-server[15394]: Wed, 01 Feb 2017 20:13:51 GMT xo:api dan@mydomain.com | backup.scanFiles(...) [1s] =!> Error: Command failed: mount --options=loop,ro --source=/dev/centos/root --target=/tmp/tmp-15394LhJ5uBDdCp5K
    Feb 01 14:13:51 xo-5 xo-server[15394]: mount: cannot mount /dev/loop1 read-only
    


  • Anyone have a valid XOA license to test against the same backup repository? Mine has expired.



  • @Danp said:

    Anyone have a valid XOA license to test against the same backup repository? Mine has expired.

    I'm sure @olivierlambert will renew it for a few days for you.

    All seems to be working fine here.



  • @Danp I extended your trial 😉



  • @olivierlambert Thanks!



  • Tested in XOA. Still getting errors. This is what I get when I select the disk --

    Feb  1 17:18:01 xoa xo-server[5596]: Wed, 01 Feb 2017 22:18:01 GMT xo:api admin@admin.net | resourceSet.getAll(...) [7ms] ==> array
    Feb  1 17:18:05 xoa systemd[1]: Starting LVM2 PV scan on device 7:0...
    Feb  1 17:18:05 xoa systemd[1]: Started LVM2 PV scan on device 7:0.
    Feb  1 17:18:05 xoa systemd-udevd[5675]: failed to execute '/bin/systemd-run' '/bin/systemd-run /sbin/lvm pvscan --cache 7:0': No such file or directory
    Feb  1 17:18:05 xoa systemd[1]: Stopping LVM2 PV scan on device 7:0...
    Feb  1 17:18:05 xoa systemd[1]: Stopped LVM2 PV scan on device 7:0.
    Feb  1 17:18:05 xoa xo-server[5596]: Wed, 01 Feb 2017 22:18:05 GMT xo:perf blocked for 29ms
    Feb  1 17:18:05 xoa xo-server[5596]: [Warn] Possibly unhandled rejection: Error: Command failed: pvs --noheading --nosuffix --nameprefixes --unbuffered --units b -o vg_name /dev/loop0
    Feb  1 17:18:05 xoa xo-server[5596]: File descriptor 12 (/var/lib/xo-server/data/leveldb/000019.log) leaked on pvs invocation. Parent PID 5596: node
    Feb  1 17:18:05 xoa xo-server[5596]: File descriptor 13 (/var/lib/xo-server/data/leveldb/LOG) leaked on pvs invocation. Parent PID 5596: node
    Feb  1 17:18:05 xoa xo-server[5596]: File descriptor 14 (/var/lib/xo-server/data/leveldb/MANIFEST-000017) leaked on pvs invocation. Parent PID 5596: node
    Feb  1 17:18:05 xoa xo-server[5596]: File descriptor 16 (/var/lib/xo-server/data/leveldb/LOCK) leaked on pvs invocation. Parent PID 5596: node
    Feb  1 17:18:05 xoa xo-server[5596]: Failed to find device "/dev/loop0"
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise.all.then.arr (/usr/local/lib/node_modules/xo-server/node_modules/execa/index.js:201:11)
    Feb  1 17:18:05 xoa xo-server[5596]: at tryCatcher (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/util.js:16:23)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromiseFromHandler (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:510:31)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromise (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:567:18)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromise0 (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:612:10)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromises (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:691:18)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._fulfill (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:636:18)
    Feb  1 17:18:05 xoa xo-server[5596]: at PromiseArray._resolve (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise_array.js:125:19)
    Feb  1 17:18:05 xoa xo-server[5596]: at PromiseArray._promiseFulfilled (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise_array.js:143:14)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromise (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:572:26)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromise0 (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:612:10)
    Feb  1 17:18:05 xoa xo-server[5596]: at Promise._settlePromises (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/promise.js:691:18)
    Feb  1 17:18:05 xoa xo-server[5596]: at Async._drainQueue (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/async.js:138:16)
    Feb  1 17:18:05 xoa xo-server[5596]: at Async._drainQueues (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/async.js:148:10)
    Feb  1 17:18:05 xoa xo-server[5596]: at Immediate.Async.drainQueues (/usr/local/lib/node_modules/xo-server/node_modules/bluebird/js/release/async.js:17:14)
    Feb  1 17:18:05 xoa xo-server[5596]: Wed, 01 Feb 2017 22:18:05 GMT xo:api admin@admin.net | backup.scanDisk(...) [195ms] ==> object
    


  • Are you sure you have a recent XOA?



  • @olivierlambert Yes, just updated today using the built-in upgrade process.



  • No I mean a recent Appliance, not if you are updated.


Log in to reply