SOLVED TASK ERROR: could not restore snapshots to tmpdir: unexpected file type:

R

roadrunner_rad

Active Member
Aug 6, 2019
51
5
28
62
Hi,

while doing a selective TEST restore from tape in a Proxmox Backup Server 1.1-10 we get the following error:

Code: 
2021-06-18T10:23:54+02:00: Mediaset 'e773924f-5861-4a49-b2bb-1abcb59bce3f'
2021-06-18T10:23:54+02:00: Pool: XXXXXX
2021-06-18T10:23:56+02:00: found snapshot host/vpnout/2021-05-24T06:35:10Z on FA3645L5: file 2148
2021-06-18T10:23:56+02:00: Phase 1: temporarily restore snapshots to temp dir
2021-06-18T10:23:56+02:00: loading media 'FA3645L5' into drive 'HPLTO'
2021-06-18T10:25:27+02:00: found media label FA3645L5 (570a8a01-307f-4ca8-b245-da89e7719b9d)
2021-06-18T10:25:27+02:00: was at file 2, moving to 2148
2021-06-18T10:27:23+02:00: now at file 2147
2021-06-18T10:27:23+02:00: TASK ERROR: could not restore snapshots to tmpdir: unexpected file type: [109, 49, 99, 109, 215, 2, 131, 191]

What are we missng ?
Regards Joachim
 
root@pbs:~# proxmox-backup-manager versions --verbose
proxmox-backup 1.0-4 running kernel: 5.4.119-1-pve
proxmox-backup-server 1.1.10-1 running version: 1.1.10
pve-kernel-5.4 6.4-3
pve-kernel-helper 6.4-3
pve-kernel-5.4.119-1-pve 5.4.119-1
pve-kernel-5.4.114-1-pve 5.4.114-1
pve-kernel-5.4.106-1-pve 5.4.106-1
pve-kernel-5.4.44-2-pve 5.4.44-2
ifupdown2 3.0.0-1+pve3
libjs-extjs 6.0.1-10
proxmox-backup-docs 1.1.10-1
proxmox-backup-client 1.1.10-1
proxmox-mini-journalreader 1.1-1
proxmox-widget-toolkit 2.5-6
pve-xtermjs 4.7.0-3
smartmontools 7.2-pve2
zfsutils-linux 2.0.4-pve1
 
what kind of drive (library?) do you use ?
 
ok can you try the following commands (and post the output here please)
replace <YOUR_DRIVE> with the drive id you gave it

Code: 
pmt asf 0 --drive <YOUR_DRIVE>
pmt status --drive <YOUR_DRIVE>
pmt asf 1 --drive <YOUR_DRIVE>
pmt status --drive <YOUR_DRIVE>
pmt asf 1000 --drive <YOUR_DRIVE>
pmt status --drive <YOUR_DRIVE>

note this will try to move to different files on the tape (pmt asf) and print the status after that (pmt status)
 
OK here is the output, if you need more info, don't hesitate to ask:

Code: 
root@pbs:~# pmt asf 0 --drive HPLTO
using device /dev/tape/by-id/scsi-35001438016073e13-sg
root@pbs:~# echo $?
0
root@pbs:~# pmt status --drive HPLTO
using device /dev/tape/by-id/scsi-35001438016073e13-sg
{
  "vendor": "HP",
  "product": "Ultrium 5-SCSI",
  "revision": "Y5BW",
  "blocksize": 0,
  "compression": true,
  "buffer-mode": 1,
  "density": "LTO5",
  "alert-flags": "(empty)",
  "file-number": 0,
  "block-number": 0,
  "manufactured": 1358294400,
  "bytes-read": 133639962624,
  "bytes-written": 24829209083904,
  "volume-mounts": 82,
  "medium-passes": 686,
  "medium-wearout": 0.042875
}
root@pbs:~# pmt asf 1 --drive HPLTO
using device /dev/tape/by-id/scsi-35001438016073e13-sg
Error: locate file 0 failed - Medium Error, Additional sense: Recorded entity not found
root@pbs:~# pmt status --drive HPLTO
using device /dev/tape/by-id/scsi-35001438016073e13-sg
{
  "vendor": "HP",
  "product": "Ultrium 5-SCSI",
  "revision": "Y5BW",
  "blocksize": 0,
  "compression": true,
  "buffer-mode": 1,
  "density": "LTO5",
  "alert-flags": "READ_WARNING",
  "file-number": 0,
  "block-number": 0,
  "manufactured": 1358294400,
  "bytes-read": 133639962624,
  "bytes-written": 24829209083904,
  "volume-mounts": 82,
  "medium-passes": 686,
  "medium-wearout": 0.042875
}
root@pbs:~# pmt asf 1000 --drive HPLTO
using device /dev/tape/by-id/scsi-35001438016073e13-sg
root@pbs:~# pmt status --drive HPLTO
using device /dev/tape/by-id/scsi-35001438016073e13-sg
{
  "vendor": "HP",
  "product": "Ultrium 5-SCSI",
  "revision": "Y5BW",
  "blocksize": 0,
  "compression": true,
  "buffer-mode": 1,
  "density": "LTO5",
  "alert-flags": "READ_WARNING",
  "file-number": 999,
  "block-number": 2043797,
  "manufactured": 1358294400,
  "bytes-read": 133843386368,
  "bytes-written": 24829209083904,
  "volume-mounts": 82,
  "medium-passes": 686,
  "medium-wearout": 0.042875
}
 
ok it seems that hp drives behave a little differently for the scsi locate command...
i'll think how we can work around that...

for now it seem you're not be able to use the single snapshot restore feature
 
Hi Dominik,

thx for your answer, as I wrote it's still a test we did. If I can assist you in testing oder analyzing please let me know...

Regards
Joachim
 
Hi Dominik,

ok, I will give this a try but I'm not familiar with building proxmox-backup-server components.
Do you have a hint or link for me how to handle those patches and build the patches version ?

Regards
Joachim
 
Hi Dominik,

the same problem here!

Code: 
2021-07-12T09:45:31+02:00: Mediaset '2b65fadd-d72c-46d3-803e-a03b4553e411'
2021-07-12T09:45:31+02:00: Pool: Pool_pbs_01
2021-07-12T09:45:32+02:00: found snapshot vm/999/2021-03-26T23:54:52Z on pbs_01_2: file 234
2021-07-12T09:45:32+02:00: found snapshot vm/122/2021-07-04T01:27:22Z on pbs_01_2: file 204
2021-07-12T09:45:32+02:00: Phase 1: temporarily restore snapshots to temp dir
2021-07-12T09:46:32+02:00: found media label pbs_01_2 (dc20e026-a1e6-40f3-8a70-83b7032aeb46)
2021-07-12T09:46:32+02:00: was at file 2, moving to 204
2021-07-12T09:47:24+02:00: now at file 203
2021-07-12T09:47:24+02:00: TASK ERROR: could not restore snapshots to tmpdir: unexpected file type: [109, 49, 99, 109, 215, 2, 131, 191]

External Tandberg (HP!) LTO5 Drive.
Part: 3520-LTO
Prod.#: AQ281W#390

Code: 
proxmox-backup-server: 1.1.10-1 (running version: 1.1.10)



Hope the bug will fixed in the next release :)

Regards
Thorsten
 
Problem soved with release 1.1.12-1!


Code: 
2021-07-12T13:30:11+02:00: Mediaset '2b65fadd-d72c-46d3-803e-a03b4553e411'
2021-07-12T13:30:11+02:00: Pool: Pool_pbs_01
2021-07-12T13:30:12+02:00: found snapshot vm/122/2021-07-04T01:27:22Z on pbs_01_2: file 204
2021-07-12T13:30:12+02:00: found snapshot vm/999/2021-03-26T23:54:52Z on pbs_01_2: file 234
2021-07-12T13:30:12+02:00: Phase 1: temporarily restore snapshots to temp dir
2021-07-12T13:30:12+02:00: Checking for media 'pbs_01_2' in drive 'LTO5'
2021-07-12T13:31:02+02:00: found media label pbs_01_2 (dc20e026-a1e6-40f3-8a70-83b7032aeb46)
2021-07-12T13:31:02+02:00: was at file 2, moving to 204
2021-07-12T13:32:14+02:00: now at file 204
2021-07-12T13:32:14+02:00: File 204: snapshot archive local-4tb-1:vm/122/2021-07-04T01:27:22Z
2021-07-12T13:32:14+02:00: was at file 205, moving to 234
2021-07-12T13:33:18+02:00: now at file 234
2021-07-12T13:33:18+02:00: File 234: snapshot archive local-4tb-1:vm/999/2021-03-26T23:54:52Z
2021-07-12T13:35:24+02:00: all chunks exist already, skipping phase 2...
2021-07-12T13:35:24+02:00: Phase 3: copy snapshots from temp dir to datastores
2021-07-12T13:35:24+02:00: Restore snapshot 'vm/122/2021-07-04T01:27:22Z' done
2021-07-12T13:35:24+02:00: Restore snapshot 'vm/999/2021-03-26T23:54:52Z' done
2021-07-12T13:35:24+02:00: Restore mediaset '2b65fadd-d72c-46d3-803e-a03b4553e411' done
2021-07-12T13:35:24+02:00: TASK OK
 
can confirm that tape move are working now with my HP TAPE Drive on PBS 1.1.12 but stumbling into the next issue:

2021-07-12T19:31:43+02:00: Mediaset 'e773924f-5861-4a49-b2bb-1abcb59bce3f'
2021-07-12T19:31:43+02:00: Pool: XXXXXX
2021-07-12T19:31:45+02:00: found snapshot host/pxy/2021-05-26T04:52:38Z on FA3645L5: file 2238
2021-07-12T19:31:45+02:00: Phase 1: temporarily restore snapshots to temp dir
2021-07-12T19:31:45+02:00: loading media 'FA3645L5' into drive 'HPLTO'
2021-07-12T19:32:11+02:00: found media label FA3645L5 (570a8a01-307f-4ca8-b245-da89e7719b9d)
2021-07-12T19:32:11+02:00: was at file 2, moving to 2238
2021-07-12T19:34:23+02:00: now at file 2238
2021-07-12T19:34:23+02:00: File 2238: snapshot archive XXXXXX:host/pxy/2021-05-26T04:52:38Z
2021-07-12T19:34:23+02:00: Phase 2: restore chunks to datastores
2021-07-12T19:34:23+02:00: loading media 'FA3645L5' into drive 'HPLTO'
2021-07-12T19:35:30+02:00: found media label FA3645L5 (570a8a01-307f-4ca8-b245-da89e7719b9d)
2021-07-12T19:35:30+02:00: was at file 2, moving to 197
2021-07-12T19:36:53+02:00: now at file 197
2021-07-12T19:36:53+02:00: File 197: chunk archive for datastore 'XXXXXX'
2021-07-12T19:36:53+02:00: TASK ERROR: No such file or directory (os error 2)

What file or directory is missing there ? I love such error messages that tell only trivial things but not the relevant information !!!

One note I'm restoreing to another pool than the pool backed by the tape...
 
roadrunner_rad said:
What file or directory is missing there ? I love such error messages that tell only trivial things but not the relevant information !!!
Click to expand...
thats a good question and i understand your feeling regarding such errors...
in rust, bubbling up erros is done 'too easily' and one often forgets to add the context to the error message...

i'll check the code what could be wrong here...
 
ok, i checked the code, and the only way i could reproduce this behaviour (at least until now) is if one of the precreated chunk dirs was missing
in the datastore directory there is a '.chunks' folder which must contain directories named 0000 to FFFF
can you check if that is the case for you?
a fast way is to do a
Code: 
ls -l /path/to/datastore/.chunks/ | wc -l
the number should be 65537 (2^16 + 1 (because of ls output))
 
Thank you for the quick reply,

As I wrote I have two datastores one for the restore tests (no backup was ever executed to this store)


root@pbs:~# ls -l /mnt/datastore/TEST/.chunks/ | wc -l
1

The other one contains the number of files you expected:

root@pbs:~# ls -l /mnt/datastore/XXXXXX/.chunks/ |wc -l
65537

As an additional test I tried to run a backup to the TEST store with the same error. When is the .chunks directory created at storage creation ?

Is there a workaround to supply the missing directory structure via shell script or is there missing more ?
 
Details from failed Backup

903: 2021-07-13 11:09:18 INFO: Starting Backup of VM 903 (qemu)
903: 2021-07-13 11:09:18 INFO: status = stopped
903: 2021-07-13 11:09:18 INFO: backup mode: stop
903: 2021-07-13 11:09:18 INFO: ionice priority: 7
903: 2021-07-13 11:09:18 INFO: VM Name: vpnin
903: 2021-07-13 11:09:18 INFO: include disk 'scsi0' 'VMSTORE:903/vm-903-disk-0.qcow2' 5G
903: 2021-07-13 11:09:18 INFO: creating Proxmox Backup Server archive 'vm/903/2021-07-13T09:09:18Z'
903: 2021-07-13 11:09:18 INFO: starting kvm to execute backup task
903: 2021-07-13 11:09:19 ERROR: VM 903 qmp command 'backup' failed - backup register image failed: command error: No such file or directory (os error 2)
903: 2021-07-13 11:09:19 INFO: aborting backup job
903: 2021-07-13 11:09:19 INFO: stopping kvm after backup task
903: 2021-07-13 11:09:20 ERROR: Backup of VM 903 failed - VM 903 qmp command 'backup' failed - backup register image failed: command error: No such file or directory (os error 2)
 
Hi Dominik,

once again thank you for pbs and the fast and precise support. Solved the datastore issue and now backup and tape restore with HP LTO Drive works as expected!
 
You must log in or register to reply here.

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom