[Vchanger-users] Again wrong media and volume on error...
Brought to you by:
jaybus2
Menu
▾
▴
[Vchanger-users] Again wrong media and volume on error...
|
From: Marco G. <ga...@li...> - 2023-05-08 10:10:26
|
Situation: we have found that in a site there was a (phisical) labeling error, that we have now corrected. Practically media 1 and 2 (or 0 and 1, if you prefere) was swapped. Clerly after 'consuming' media 3 (or 2), now we have inserted the correct media 1 (or 0), but the retention was wrong (the expired media is the 2 (or 1). See the volume report: *list media pool=VEN-SD-SDPVE2RDXPool +---------+---------------------+-----------+---------+-----------------+----------+--------------+---------+------+-----------+-----------+---------+----------+---------------------+-----------+ | mediaid | volumename | volstatus | enabled | volbytes | volfiles | volretention | recycle | slot | inchanger | mediatype | voltype | volparts | lastwritten | expiresin | +---------+---------------------+-----------+---------+-----------------+----------+--------------+---------+------+-----------+-----------+---------+----------+---------------------+-----------+ | 45 | SDPVE2RDX_0000_0000 | Used | 1 | 333,592,723 | 0 | 1,728,000 | 1 | 1 | 1 | RDX | 1 | 0 | 2023-04-26 23:02:30 | 738,936 | | 46 | SDPVE2RDX_0000_0001 | Used | 1 | 181,875,638,823 | 42 | 1,728,000 | 1 | 2 | 1 | RDX | 1 | 0 | 2023-04-21 22:02:41 | 303,347 | | 47 | SDPVE2RDX_0000_0002 | Used | 1 | 274,304,626 | 0 | 1,728,000 | 1 | 3 | 1 | RDX | 1 | 0 | 2023-04-27 23:03:04 | 825,370 | | 48 | SDPVE2RDX_0000_0003 | Used | 1 | 136,766,487 | 0 | 1,728,000 | 1 | 4 | 1 | RDX | 1 | 0 | 2023-04-23 23:03:24 | 479,790 | | 49 | SDPVE2RDX_0000_0004 | Used | 1 | 98,558,078 | 0 | 1,728,000 | 1 | 5 | 1 | RDX | 1 | 0 | 2023-04-22 23:03:04 | 393,370 | | 50 | SDPVE2RDX_0000_0005 | Used | 1 | 43,774,768,005 | 10 | 1,728,000 | 1 | 6 | 1 | RDX | 1 | 0 | 2023-04-23 02:07:07 | 404,413 | | 51 | SDPVE2RDX_0000_0006 | Used | 1 | 94,488,618 | 0 | 1,728,000 | 1 | 7 | 1 | RDX | 1 | 0 | 2023-04-24 23:02:16 | 566,122 | | 52 | SDPVE2RDX_0000_0007 | Used | 1 | 116,431,192 | 0 | 1,728,000 | 1 | 8 | 1 | RDX | 1 | 0 | 2023-04-25 23:02:20 | 652,526 | | 53 | SDPVE2RDX_0000_0008 | Disabled | 1 | 234 | 0 | 1,728,000 | 1 | 9 | 1 | RDX | 1 | 0 | | 0 | | 54 | SDPVE2RDX_0000_0009 | Disabled | 1 | 234 | 0 | 1,728,000 | 1 | 10 | 1 | RDX | 1 | 1 | 2022-08-25 23:01:40 | 0 | | 75 | SDPVE2RDX_0001_0000 | Error | 1 | 1 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-16 02:06:08 | 0 | | 76 | SDPVE2RDX_0001_0001 | Used | 1 | 348,836,026 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-19 23:02:28 | 134,134 | | 77 | SDPVE2RDX_0001_0002 | Used | 1 | 257,396,874 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-20 23:02:40 | 220,546 | | 78 | SDPVE2RDX_0001_0003 | Error | 1 | 1 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-16 23:02:44 | 0 | | 79 | SDPVE2RDX_0001_0004 | Error | 1 | 1 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-15 23:03:05 | 0 | | 80 | SDPVE2RDX_0001_0005 | Error | 1 | 1 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-17 23:01:55 | 0 | | 81 | SDPVE2RDX_0001_0006 | Used | 1 | 381,105,354 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-18 23:03:31 | 47,797 | | 82 | SDPVE2RDX_0001_0007 | Error | 1 | 1 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-14 22:00:20 | 0 | | 83 | SDPVE2RDX_0001_0008 | Disabled | 1 | 234 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | | 0 | | 84 | SDPVE2RDX_0001_0009 | Disabled | 1 | 234 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 1 | 2022-10-12 23:01:43 | 0 | | 166 | SDPVE2RDX_0002_0001 | Used | 1 | 43,483,736,128 | 10 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-30 02:05:27 | 1,009,113 | | 167 | SDPVE2RDX_0002_0002 | Used | 1 | 432,436,677 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-05-02 23:02:13 | 1,257,319 | | 168 | SDPVE2RDX_0002_0003 | Used | 1 | 157,886,453 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-30 23:03:06 | 1,084,572 | | 169 | SDPVE2RDX_0002_0004 | Used | 1 | 234,957,948 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-05-01 23:02:06 | 1,170,912 | | 170 | SDPVE2RDX_0002_0005 | Used | 1 | 291,189,870 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 1 | 2023-05-04 23:01:48 | 1,430,094 | | 171 | SDPVE2RDX_0002_0006 | Used | 1 | 255,584,790 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 1 | 2023-05-03 23:02:15 | 1,343,721 | | 172 | SDPVE2RDX_0002_0007 | Used | 1 | 182,008,772,526 | 42 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-28 22:01:26 | 908,072 | | 173 | SDPVE2RDX_0002_0008 | Disabled | 1 | 234 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | | 0 | | 174 | SDPVE2RDX_0002_0009 | Disabled | 1 | 234 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 1 | 2022-09-23 21:53:46 | 0 | | 295 | SDPVE2RDX_0002_0000 | Used | 1 | 97,465,011 | 0 | 1,728,000 | 1 | 0 | 0 | RDX | 1 | 0 | 2023-04-29 23:02:06 | 998,112 | +---------+---------------------+-----------+---------+-----------------+----------+--------------+---------+------+-----------+-----------+---------+----------+---------------------+-----------+ So it is right that Bacula does not use volumes in media 0 (they are not expired), but try and try to use the (just expired) volume in media 1, clearly putting them on error: 08-May 09:35 lnfbacula-dir JobId 6648: Recycled volume "SDPVE2RDX_0001_0007" 08-May 09:36 sdpve2-sd JobId 6648: Warning: mount.c:215 Open of File device "RDXStorage0" (/var/spool/vchanger/SDPVE2RDX/0) Volume "SDPVE2RDX_0001_0007" failed: ERR=file_dev.c:190 Could not open(/var/spool/vchanger/SDPVE2RDX/0,OPEN_READ_WRITE,0640): ERR=No such file or directory 08-May 09:36 sdpve2-sd JobId 6648: Marking Volume "SDPVE2RDX_0001_0007" in Error in Catalog. 08-May 09:37 lnfbacula-dir JobId 6668: Recycled volume "SDPVE2RDX_0001_0004" 08-May 09:37 sdpve2-sd JobId 6668: Warning: mount.c:215 Open of File device "RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) Volume "SDPVE2RDX_0001_0004" failed: ERR=file_dev.c:190 Could not open(/var/spool/vchanger/SDPVE2RDX/1,OPEN_READ_WRITE,0640): ERR=No such file or directory 08-May 09:37 sdpve2-sd JobId 6668: Marking Volume "SDPVE2RDX_0001_0004" in Error in Catalog. 08-May 09:37 lnfbacula-dir JobId 6668: Recycled volume "SDPVE2RDX_0001_0000" 08-May 09:37 sdpve2-sd JobId 6668: Warning: mount.c:215 Open of File device "RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) Volume "SDPVE2RDX_0001_0000" failed: ERR=file_dev.c:190 Could not open(/var/spool/vchanger/SDPVE2RDX/1,OPEN_READ_WRITE,0640): ERR=No such file or directory 08-May 09:37 sdpve2-sd JobId 6668: Marking Volume "SDPVE2RDX_0001_0000" in Error in Catalog. 08-May 09:37 lnfbacula-dir JobId 6668: Recycled volume "SDPVE2RDX_0001_0003" 08-May 09:37 sdpve2-sd JobId 6668: Warning: mount.c:215 Open of File device "RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) Volume "SDPVE2RDX_0001_0003" failed: ERR=file_dev.c:190 Could not open(/var/spool/vchanger/SDPVE2RDX/1,OPEN_READ_WRITE,0640): ERR=No such file or directory 08-May 09:37 sdpve2-sd JobId 6668: Marking Volume "SDPVE2RDX_0001_0003" in Error in Catalog. if i purge volume in error, at subsequent run bacula put them on error. I've tried to do an: update slots storage=SDPVE2RDX repurge all volumes in error, but nothing changed. Back in error. vchanger log report no error: May 08 09:30:59: [32513]: restored state of magazine 0 May 08 09:30:59: [32513]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 has udev assigned device /dev/sdc1 May 08 09:30:59: [32513]: filesystem 5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 (device /dev/sdc1) mounted at /mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 May 08 09:30:59: [32513]: magazine 0 has 10 volumes on /mnt/vchanger/5ba3d8a2-80e2-4322-9d83-839d2f6dc8b4 May 08 09:30:59: [32513]: 10 volumes on magazine 0 assigned slots 1-10 May 08 09:30:59: [32513]: magazine 1 is not mounted May 08 09:30:59: [32513]: magazine 2 is not mounted May 08 09:30:59: [32513]: saved state of magazine 0 May 08 09:30:59: [32513]: saved dynamic configuration (max used slot: 10) May 08 09:30:59: [32513]: drive 0 previously unloaded May 08 09:30:59: [32513]: ==== preforming LOADED command May 08 09:30:59: [32513]: SUCCESS reporting drive 0 loaded from slot 0 What happened?! Why bacula try to mount volume not in slots? The only strange things is the SD status: *status storage=SDPVE2RDX Connecting to Storage daemon SDPVE2RDX at sdpve2.sd.lnf.it:9103 sdpve2-sd Version: 9.4.2 (04 February 2019) x86_64-pc-linux-gnu debian 10.5 Daemon started 09-Mar-23 13:05. Jobs: run=65, running=1. Heap: heap=8,192 smbytes=799,871 max_bytes=1,156,238 bufs=211 max_bufs=265 Sizes: boffset_t=8 size_t=8 int32_t=4 int64_t=8 mode=0,0 newbsr=0 Res: ndevices=3 nautochgr=1 Running Jobs: Writing: Full Backup job VEN-SD-SDPVE2-VMs JobId=6648 Volume="" pool="VEN-SD-SDPVE2RDXPool" device="RDXStorage0" (/var/spool/vchanger/SDPVE2RDX/0) spooling=0 despooling=0 despool_wait=0 Files=0 Bytes=0 AveBytes/sec=0 LastBytes/sec=0 FDReadSeqNo=6 in_msg=6 out_msg=400 fd=7 Writing: Incremental Backup job VEN-SD-Sdinny JobId=6668 Volume="" pool="VEN-SD-SDPVE2RDXPool" device="RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) spooling=0 despooling=0 despool_wait=0 Files=0 Bytes=0 AveBytes/sec=0 LastBytes/sec=0 FDReadSeqNo=6 in_msg=6 out_msg=147 fd=5 ==== Jobs waiting to reserve a drive: ==== Terminated Jobs: JobId Level Files Bytes Status Finished Name =================================================================== 6330 Incr 8,449 273.7 M OK 27-Apr-23 23:03 VEN-SD-Sdinny 6365 Full 627,377 181.8 G OK 28-Apr-23 22:08 VEN-SD-Sdinny 6386 Incr 1,565 97.32 M OK 29-Apr-23 23:02 VEN-SD-Sdinny 6408 Full 6 43.45 G OK 30-Apr-23 02:05 VEN-SD-SDPVE2-VMs 6427 Incr 1,508 157.7 M OK 30-Apr-23 23:03 VEN-SD-Sdinny 6461 Incr 1,122 234.7 M OK 01-May-23 23:02 VEN-SD-Sdinny 6498 Incr 7,495 431.8 M OK 02-May-23 23:02 VEN-SD-Sdinny 6533 Incr 9,558 255.0 M OK 03-May-23 23:02 VEN-SD-Sdinny 6568 Incr 10,131 290.5 M OK 04-May-23 23:01 VEN-SD-Sdinny 6603 Full 0 0 Cancel 07-May-23 20:01 VEN-SD-Sdinny ==== Device status: Autochanger "RDXAutochanger" with devices: "RDXStorage0" (/var/spool/vchanger/SDPVE2RDX/0) "RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) "RDXStorage2" (/var/spool/vchanger/SDPVE2RDX/2) Device File: "RDXStorage0" (/var/spool/vchanger/SDPVE2RDX/0) is not open. Device is BLOCKED waiting to create a volume for: Pool: VEN-SD-SDPVE2RDXPool Media type: RDX Drive 0 is not loaded. == Device File: "RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) is not open. Device is BLOCKED waiting to create a volume for: Pool: VEN-SD-SDPVE2RDXPool Media type: RDX Slot 6 was last loaded in drive 1. == Device File: "RDXStorage2" (/var/spool/vchanger/SDPVE2RDX/2) is not open. Slot 8 was last loaded in drive 2. == ==== Used Volume status: Reserved volume: SDPVE2RDX_0001_0003 on File device "RDXStorage1" (/var/spool/vchanger/SDPVE2RDX/1) Reader=0 writers=0 reserves=1 volinuse=0 worm=0 Reserved volume: SDPVE2RDX_0001_0005 on File device "RDXStorage0" (/var/spool/vchanger/SDPVE2RDX/0) Reader=0 writers=0 reserves=1 volinuse=0 worm=0 ==== Attr spooling: 0 active jobs, 0 bytes; 63 total jobs, 178,915,351 max bytes. ==== Thanks. -- chi si convertiva nel novanta ne era dispensato nel novantuno (F. De Andre`) |
