Menu
▾
▴
[Bacula-bugs] [bacula 0001759]: Bacula creates backup on multiple volumens that can't be restored
|
From: Mantis B. T. <no...@bu...> - 2011-08-29 09:32:32
|
A NOTE has been added to this issue. ====================================================================== http://bugs.bacula.org/view.php?id=1759 ====================================================================== Reported By: bartosz.cisek Assigned To: ebollengier ====================================================================== Project: bacula Issue ID: 1759 Category: Storage Daemon Reproducibility: unable to reproduce Severity: major Priority: low Status: assigned ====================================================================== Date Submitted: 2011-08-17 12:12 BST Last Modified: 2011-08-29 10:32 BST ====================================================================== Summary: Bacula creates backup on multiple volumens that can't be restored Description: >From time to time bacula creates backup that can't be restored. After some research I found that jobs that match SQL query are problematic: SELECT JobId FROM JobMedia WHERE StartBlock <> 0 AND EndBlock = 0; All those jobs are spanning two volumens. First one looks broken (EndBlock and EndFile equals 0 while StartBlock and StartFile are not), second looks ok according to source code [1]. [1] http://www.bacula.org/git/cgit.cgi/bacula/tree/bacula/src/stored/block.c#n620 Steps to Reproduce: Each restore end the same way: "Restore OK -- warning file count mismatch" Additional Information: http://sourceforge.net/mailarchive/forum.php?thread_name=201108101307.p7AD7pwf012352%40higson.cam.lispworks.com&forum_name=bacula-users ====================================================================== ---------------------------------------------------------------------- (0005946) ebollengier (administrator) - 2011-08-17 13:11 http://bugs.bacula.org/view.php?id=1759#c5946 ---------------------------------------------------------------------- What you describe is very serious, unfortunately, I can't reproduce it here (see my output). Please, attach the bootstrap file generated by the job (option WriteBootStrap) and also the bootstrap generated by the restore command. *list files jobid=5 +---------------------------+ | filename | +---------------------------+ | /tmp/regress/build/po/big | +---------------------------+ +-------+---------+---------------------+------+-------+----------+-----------+-----------+ | jobid | name | starttime | type | level | jobfiles | jobbytes | jobstatus | +-------+---------+---------------------+------+-------+----------+-----------+-----------+ | 5 | SpanVol | 2011-08-17 14:07:11 | B | F | 1 | 5,120,000 | T | +-------+---------+---------------------+------+-------+----------+-----------+-----------+ *list jobmedia jobid=5 +-------+------------+------------+-----------+ | jobid | volumename | firstindex | lastindex | +-------+------------+------------+-----------+ | 5 | kk | 1 | 1 | | 5 | ll | 1 | 1 | +-------+------------+------------+-----------+ +-------+---------+---------------------+------+-------+----------+-----------+-----------+ | jobid | name | starttime | type | level | jobfiles | jobbytes | jobstatus | +-------+---------+---------------------+------+-------+----------+-----------+-----------+ | 5 | SpanVol | 2011-08-17 14:07:11 | B | F | 1 | 5,120,000 | T | +-------+---------+---------------------+------+-------+----------+-----------+-----------+ *restore First you select one or more JobIds that contain files to be restored. You will be presented several methods of specifying the JobIds. Then you will be allowed to select which files from those JobIds are to be restored. To select the JobIds, you have the following choices: 1: List last 20 Jobs run 2: List Jobs where a given File is saved 3: Enter list of comma separated JobIds to select 4: Enter SQL list command 5: Select the most recent backup for a client 6: Select backup for a client before a specified time 7: Enter a list of files to restore 8: Enter a list of files to restore before a specified time 9: Find the JobIds of the most recent backup for a client 10: Find the JobIds for a backup for a client before a specified time 11: Enter a list of directories to restore for found JobIds 12: Select full restore to a specified Job date 13: Cancel Select item: (1-13): 5 Automatically selected Client: 127.0.0.1-fd Automatically selected FileSet: Full Set +-------+-------+----------+-----------+---------------------+------------+ | jobid | level | jobfiles | jobbytes | starttime | volumename | +-------+-------+----------+-----------+---------------------+------------+ | 5 | F | 1 | 5,120,000 | 2011-08-17 14:07:11 | kk | | 5 | F | 1 | 5,120,000 | 2011-08-17 14:07:11 | ll | +-------+-------+----------+-----------+---------------------+------------+ You have selected the following JobId: 5 Building directory tree for JobId(s) 5 ... 1 files inserted into the tree. You are now entering file selection mode where you add (mark) and remove (unmark) files to be restored. No files are initially added, unless you used the "all" keyword on the command line. Enter "done" to leave this mode. cwd is: / $ m * 1 file marked. $ done Bootstrap records written to /tmp/regress/working/127.0.0.1-dir.restore.1.bsr The job will require the following Volume(s) Storage(s) SD Device(s) =========================================================================== kk File FileStorage ll File FileStorage Volumes marked with "*" are online. 1 file selected to be restored. Run Restore job JobName: RestoreFiles Bootstrap: /tmp/regress/working/127.0.0.1-dir.restore.1.bsr Where: /tmp/regress/tmp/bacula-restores Replace: always FileSet: Full Set Backup Client: 127.0.0.1-fd Restore Client: 127.0.0.1-fd Storage: File When: 2011-08-17 14:07:41 Catalog: MyCatalog Priority: 10 Plugin Options: *None* OK to run? (yes/mod/no): Job queued. JobId=6 * * *m 17-Aug 14:07 127.0.0.1-dir JobId 6: Start Restore Job RestoreFiles.2011-08-17_14.07.43_10 17-Aug 14:07 127.0.0.1-dir JobId 6: Using Device "FileStorage" 17-Aug 14:07 127.0.0.1-sd JobId 6: Ready to read from volume "kk" on device "FileStorage" (/tmp/regress/tmp). 17-Aug 14:07 127.0.0.1-sd JobId 6: Forward spacing Volume "kk" to file:block 0:9544. 17-Aug 14:07 127.0.0.1-sd JobId 6: End of Volume at file 0 on device "FileStorage" (/tmp/regress/tmp), Volume "kk" 17-Aug 14:07 127.0.0.1-sd JobId 6: Ready to read from volume "ll" on device "FileStorage" (/tmp/regress/tmp). 17-Aug 14:07 127.0.0.1-sd JobId 6: Forward spacing Volume "ll" to file:block 0:186. 17-Aug 14:07 127.0.0.1-sd JobId 6: End of Volume at file 0 on device "FileStorage" (/tmp/regress/tmp), Volume "ll" 17-Aug 14:07 127.0.0.1-sd JobId 6: End of all volumes. 17-Aug 14:07 127.0.0.1-dir JobId 6: Bacula 127.0.0.1-dir 4.1.20 (21Jul11): Build OS: x86_64-unknown-linux-gnu archlinux JobId: 6 Job: RestoreFiles.2011-08-17_14.07.43_10 Restore Client: 127.0.0.1-fd Start time: 17-Aug-2011 14:07:45 End time: 17-Aug-2011 14:07:45 Files Expected: 1 Files Restored: 1 Bytes Restored: 5,120,000 Rate: 0.0 KB/s FD Errors: 0 FD termination status: OK SD termination status: OK Termination: Restore OK ---------------------------------------------------------------------- (0005947) kern (administrator) - 2011-08-18 07:46 http://bugs.bacula.org/view.php?id=1759#c5947 ---------------------------------------------------------------------- I think you should start by showing us the backup job output for the job that cannot be restored, and a listing of the JobMedia records that were produced with that Job. Include your bacula-dir.conf and bacula-sd.conf files. Then show us the job output for restore that fails -- include *all* the commands that you used to run the restore job. We will probably want this with some debug level at some point. It is clear that if EndBlock and EndFile are zero, something went wrong and a restore will not be possible, but there is no reason for Bacula to create such records unless there was a failure or perhaps your catalog was produced by a bscan. Why have you indicated btape in the category field? -- btape should not be part of what is happening here. Otherwise this bug report does not make sense. ---------------------------------------------------------------------- (0005948) bartosz.cisek (reporter) - 2011-08-18 14:03 http://bugs.bacula.org/view.php?id=1759#c5948 ---------------------------------------------------------------------- I've posted most of needed info in mail thread on bacula-users (linked in task). I didn't see the point to copy paste it here ;) btape category was used because I had no idea which one to choose. Attached bacula-dir.conf and bacula-sd.conf ---------------------------------------------------------------------- (0005949) kern (administrator) - 2011-08-19 07:31 http://bugs.bacula.org/view.php?id=1759#c5949 ---------------------------------------------------------------------- Not able to reproduce. Reporter refuses information requested. Bug closed. ---------------------------------------------------------------------- (0005950) bartosz.cisek (reporter) - 2011-08-19 07:46 http://bugs.bacula.org/view.php?id=1759#c5950 ---------------------------------------------------------------------- Hi! I really don't understand your comment. I wrote I already provided all needed information, and pointed to it (bacula-users list, link attached to task). I also attached file you asked for. If I can be more helpful please tell me how. I said that copy-paste is pointless as whole information is easyly accessilble and properly linked. If you wish I'll put it here. ---------------------------------------------------------------------- (0005951) kern (administrator) - 2011-08-19 16:59 http://bugs.bacula.org/view.php?id=1759#c5951 ---------------------------------------------------------------------- Have you tried the link? It does not work for me -- well it drops me into probably thousands of possible email conversations. Providing the information here saves us time and ensures it is here for future reference. With out the information (backup/restore logs and command sequences used for restore), it is not possible to draw any conclusions). >From what I see in your conf files, you are using a virtual disk changer which is probably not part of the project and thus not supported. ---------------------------------------------------------------------- (0005952) Dan Langille (manager) - 2011-08-20 03:15 http://bugs.bacula.org/view.php?id=1759#c5952 ---------------------------------------------------------------------- bartosz.cisek: Please don't expect people to read through mailing list archives for information requested. By having you place it here, a full audit trail is created. ---------------------------------------------------------------------- (0005953) bartosz.cisek (reporter) - 2011-08-25 10:35 http://bugs.bacula.org/view.php?id=1759#c5953 ---------------------------------------------------------------------- bconsole> list files jobid=8228320 +---------------------------------+ | Filename | +---------------------------------+ | /var/lib/mysql/mysql-bin.015514 | +---------------------------------+ bconsole> list jobmedia jobid=8228320 +-----------+----------------------------+------------+-----------+ | JobId | VolumeName | FirstIndex | LastIndex | +-----------+----------------------------+------------+-----------+ | 8,228,320 | bacula-vtape-backup-000204 | 1 | 1 | | 8,228,320 | bacula-vtape-backup-000255 | 1 | 1 | +-----------+----------------------------+------------+-----------+ +-----------+------------------------------+---------------------+------+-------+----------+----------+-----------+ | JobId | Name | StartTime | Type | Level | JobFiles | JobBytes | JobStatus | +-----------+------------------------------+---------------------+------+-------+----------+----------+-----------+ | 8,228,320 | job-hostname-bin-logs | 2011-08-07 06:03:48 | B | I | 1 | 113,188 | T | +-----------+------------------------------+---------------------+------+-------+----------+----------+-----------+ 08-sie 16:25 sd-backup-3 JobId 8246008: 3307 Issuing autochanger "unload slot 233, drive 0" command. 08-sie 16:25 sd-backup-3 JobId 8246008: 3304 Issuing autochanger "load slot 255, drive 0" command. 08-sie 16:25 sd-backup-3 JobId 8246008: 3305 Autochanger "load slot 255, drive 0", status is OK. 08-sie 16:25 sd-backup-3 JobId 8246008: Ready to read from volume "bacula-vtape-backup-000255" on device "dev-vtape-backup-drive-0" (/srv/stor1/bacula-backup/vtape-backup-drive-0). 08-sie 16:25 sd-backup-3 JobId 8246008: Forward spacing Volume "bacula-vtape-backup-000255" to file:block 1:4294788096. 08-sie 16:25 sd-backup-3 JobId 8246008: End of Volume at file 1 on device "dev-vtape-backup-drive-0" (/srv/stor1/bacula-backup/vtape-backup-drive-0), Volume "bacula-vtape-backup-000255" 08-sie 16:25 sd-backup-3 JobId 8246008: 3307 Issuing autochanger "unload slot 255, drive 0" command. 08-sie 16:25 sd-backup-3 JobId 8246008: 3304 Issuing autochanger "load slot 204, drive 0" command. 08-sie 16:25 sd-backup-3 JobId 8246008: 3305 Autochanger "load slot 204, drive 0", status is OK. 08-sie 16:25 sd-backup-3 JobId 8246008: Ready to read from volume "bacula-vtape-backup-000204" on device "dev-vtape-backup-drive-0" (/srv/stor1/bacula-backup/vtape-backup-drive-0). 08-sie 16:25 sd-backup-3 JobId 8246008: Forward spacing Volume "bacula-vtape-backup-000204" to file:block 0:258294. 08-sie 16:25 sd-backup-3 JobId 8246008: End of Volume at file 0 on device "dev-vtape-backup-drive-0" (/srv/stor1/bacula-backup/vtape-backup-drive-0), Volume "bacula-vtape-backup-000204" 08-sie 16:25 sd-backup-3 JobId 8246008: End of all volumes. 08-sie 16:25 dir-db-bacula JobId 8246008: Bacula dir-db-bacula 5.0.3 (04Aug10): 08-sie-2011 16:25:04 Build OS: x86_64-pc-linux-gnu debian 5.0.6 JobId: 8246008 Job: job-restore.2011-08-08_16.25.02_13 Restore Client: fd-hd-mysql1 Start time: 08-sie-2011 16:25:04 End time: 08-sie-2011 16:25:04 Files Expected: 1 Files Restored: 0 Bytes Restored: 0 Rate: 0.0 KB/s FD Errors: 0 FD termination status: OK SD termination status: OK Termination: Restore OK -- warning file count mismatch 08-sie 16:25 dir-db-bacula JobId 8246008: Begin pruning Jobs older than 10 years . 08-sie 16:25 dir-db-bacula JobId 8246008: No Jobs found to prune. 08-sie 16:25 dir-db-bacula JobId 8246008: Begin pruning Jobs. 08-sie 16:25 dir-db-bacula JobId 8246008: No Files found to prune. 08-sie 16:25 dir-db-bacula JobId 8246008: End auto prune. bconsole> llist jobmedia jobid=8228320 Automatically selected Catalog: catalog Using Catalog "catalog" JobMediaId: 6,721,875 JobId: 8,228,320 MediaId: 3,348 VolumeName: bacula-vtape-backup-000204 FirstIndex: 1 LastIndex: 1 StartFile: 0 EndFile: 0 StartBlock: 258,294 EndBlock: 307,813 JobMediaId: 6,721,874 JobId: 8,228,320 MediaId: 3,399 VolumeName: bacula-vtape-backup-000255 FirstIndex: 1 LastIndex: 1 StartFile: 1 EndFile: 0 StartBlock: 4,294,788,096 EndBlock: 0 JobId: 8,228,320 Job: job-db-mails5-mysql-bin-logs.2011-08-07_06.03.02_57 Name: job-db-mails5-mysql-bin-logs PurgedFiles: 0 Type: B Level: I ClientId: 122 Name: fd-db-mails5 JobStatus: T SchedTime: 2011-08-07 06:03:02 StartTime: 2011-08-07 06:03:48 EndTime: 2011-08-07 06:04:15 RealEndTime: 2011-08-07 06:04:15 JobTDate: 1,312,689,855 VolSessionId: 958,674 VolSessionTime: 1,305,911,228 JobFiles: 1 JobErrors: 0 JobMissingFiles: 0 PoolId: 11 PooLname: pool-vtape-backup-daily PriorJobId: 0 FileSetId: 14 FileSet: fs-mysql-bin-logs fd-hd-mysql1: bnet.c:669-0 who=client host=x.x.x.150 port=36387 fd-hd-mysql1: job.c:263-0 <dird: Hello Director dir-db-bacula calling fd-hd-mysql1: job.c:279-0 Executing Hello command. fd-hd-mysql1: job.c:423-0 Calling Authenticate fd-hd-mysql1: cram-md5.c:73-0 send: auth cram-md5 <363898797.1313041176@...> ssl=0 fd-hd-mysql1: cram-md5.c:133-0 cram-get received: auth cram-md5 <1780993725.1313041176@...> ssl=0 fd-hd-mysql1: cram-md5.c:152-0 sending resp to challenge: 3WF6F+/mIH8NJA/FN5qqEB fd-hd-mysql1: job.c:427-0 OK Authenticate fd-hd-mysql1: job.c:263-0 <dird: JobId=8278742 Job=job-restore.2011-08-11_07.39.34_20 SDid=32608 SDtime=1312814516 Authorization=LKJG-JIJG-EHIE-GMAN-FCAF-LFEB-BPMF-IKPH fd-hd-mysql1: job.c:279-0 Executing JobId= command. fd-hd-mysql1: job.c:520-0 JobId=8278742 Auth=LKJG-JIJG-EHIE-GMAN-FCAF-LFEB-BPMF-IKPH fd-hd-mysql1: fd_plugins.c:655-0 plugin list is NULL fd-hd-mysql1: job.c:263-0 <dird: storage address=y.y.y.4 port=9103 ssl=0 Authorization=LKJG-JIJG-EHIE-GMAN-FCAF-LFEB-BPMF-IKPH fd-hd-mysql1: job.c:279-0 Executing storage command. fd-hd-mysql1: job.c:1474-0 StorageCmd: storage address=y.y.y.4 port=9103 ssl=0 Authorization=LKJG-JIJG-EHIE-GMAN-FCAF-LFEB-BPMF-IKPH fd-hd-mysql1: job.c:1453-0 set multi_restore=true fd-hd-mysql1: job.c:1491-0 Open storage: y.y.y.4:9103 ssl=0 fd-hd-mysql1: bsock.c:220-0 Current host[ipv4:y.y.y.4:9103] All host[ipv4:10.3.46.4:9103] fd-hd-mysql1: bsock.c:154-0 who=Storage daemon host=y.y.y.4 port=9103 fd-hd-mysql1: job.c:1509-0 Connection OK to SD. fd-hd-mysql1: cram-md5.c:133-0 cram-get received: auth cram-md5 <387487674.1313041176@...> ssl=0 fd-hd-mysql1: cram-md5.c:152-0 sending resp to challenge: L4/rwn+MQn+zVj/d2//Y3C fd-hd-mysql1: cram-md5.c:80-0 send: auth cram-md5 <1960026801.1313041176@...> ssl=0 fd-hd-mysql1: cram-md5.c:99-0 Authenticate OK Rxhjl7/jT7kUY2/fO5/V1C fd-hd-mysql1: job.c:1518-0 Authenticated with SD. fd-hd-mysql1: job.c:263-0 <dird: restore replace=a prelinks=0 where=/srv/bacula-restore fd-hd-mysql1: job.c:279-0 Executing restore command. fd-hd-mysql1: job.c:1824-0 restore command fd-hd-mysql1: job.c:1845-0 Got replace a, where=/srv/bacula-restore fd-hd-mysql1: job.c:1864-0 filed>dird: 2000 OK restore fd-hd-mysql1: job.c:1939-0 VolSessId=32608 VolsessT=1312814516 SF=0 EF=0 fd-hd-mysql1: job.c:1940-0 JobId=8278742 vol=DummyVolume fd-hd-mysql1: job.c:1947-0 >stored: read open session = DummyVolume 32608 1312814516 0 0 0 0 fd-hd-mysql1: job.c:1953-0 filed<stored: 3000 OK open ticket = 32608 fd-hd-mysql1: job.c:1958-0 filed: got Ticket=32608 fd-hd-mysql1: job.c:1972-0 >stored: read data 32608 fd-hd-mysql1: job.c:2018-0 3000 OK data fd-hd-mysql1: pythonlib.c:227-0 No startup module. fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=6180 Stream=4, GZIP data. fd-hd-mysql1: restore.c:288-0 Got stream: GZIP data len=6180 extract=0 fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=8971 Stream=4, GZIP data. fd-hd-mysql1: restore.c:288-0 Got stream: GZIP data len=8971 extract=0 fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=9679 Stream=4, GZIP data. fd-hd-mysql1: restore.c:288-0 Got stream: GZIP data len=9679 extract=0 fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=11403 Stream=4, GZIP data. fd-hd-mysql1: restore.c:288-0 Got stream: GZIP data len=11403 extract=0 fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=12068 Stream=4, GZIP data. fd-hd-mysql1: restore.c:288-0 Got stream: GZIP data len=12068 extract=0 fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=828 Stream=4, GZIP data. fd-hd-mysql1: restore.c:288-0 Got stream: GZIP data len=828 extract=0 fd-hd-mysql1: restore.c:271-0 Got hdr: Files=0 FilInx=1 size=16 Stream=3, MD5 digest. fd-hd-mysql1: restore.c:288-0 Got stream: MD5 digest len=16 extract=0 fd-hd-mysql1: restore.c:795-0 End Do Restore. Files=0 Bytes=0 fd-hd-mysql1: job.c:1895-0 filed>stored: read close session 32608 fd-hd-mysql1: job.c:1909-0 Done in job.c fd-hd-mysql1: job.c:263-0 <dird: endrestorefd-hd-mysql1: job.c:279-0 Executing endrestore command. fd-hd-mysql1: job.c:1925-0 end_restore_cmd fd-hd-mysql1: job.c:282-0 Quit command loop. Canceled=0 fd-hd-mysql1: runscript.c:110-0 runscript: running all RUNSCRIPT object (ClientAfterJob) JobStatus=T fd-hd-mysql1: job.c:309-0 End FD msg: 2800 End Job TermCode=84 JobFiles=0 ReadBytes=0 JobBytes=0 Errors=0 VSS=0 Encrypt=0 fd-hd-mysql1: pythonlib.c:227-0 No startup module. fd-hd-mysql1: job.c:388-0 Calling term_find_files fd-hd-mysql1: job.c:391-0 Done with term_find_files fd-hd-mysql1: jcr.c:181-0 write_last_jobs seek to 192 fd-hd-mysql1: mem_pool.c:369-0 garbage collect memory pool fd-hd-mysql1: job.c:393-0 Done with free_jcr fd-hd-mysql1: mem_pool.c:369-0 garbage collect memory pool fd-hd-mysql1: bnet.c:669-0 who=client host=x.x.x.150 port=36387 fd-hd-mysql1: job.c:263-0 <dird: Hello Director dir-db-bacula calling fd-hd-mysql1: job.c:279-0 Executing Hello command. fd-hd-mysql1: job.c:423-0 Calling Authenticate fd-hd-mysql1: cram-md5.c:73-0 send: auth cram-md5 <1933690469.1313041199@...> ssl=0 fd-hd-mysql1: cram-md5.c:133-0 cram-get received: auth cram-md5 <1448676872.1313041199@...> ssl=0 fd-hd-mysql1: cram-md5.c:152-0 sending resp to challenge: 0++157k0f1hAy5++M7/TVC fd-hd-mysql1: job.c:427-0 OK Authenticate fd-hd-mysql1: job.c:263-0 <dird: JobId=0 Job=-Console-.2011-08-11_07.38.45_19 SDid=0 SDtime=0 Authorization=dummy fd-hd-mysql1: job.c:279-0 Executing JobId= command. fd-hd-mysql1: job.c:520-0 JobId=0 Auth=dummy fd-hd-mysql1: fd_plugins.c:655-0 plugin list is NULL fd-hd-mysql1: job.c:263-0 <dird: setdebug=0 trace=0 fd-hd-mysql1: job.c:279-0 Executing setdebug= command. fd-hd-mysql1: job.c:472-0 setdebug_cmd: setdebug=0 trace=0 ---------------------------------------------------------------------- (0005954) bartosz.cisek (reporter) - 2011-08-25 10:36 http://bugs.bacula.org/view.php?id=1759#c5954 ---------------------------------------------------------------------- SELECT JobId FROM JobMedia WHERE StartBlock <> 0 AND EndBlock = 0; +---------+ | JobId | +---------+ | 8208817 | | 8208813 | | 8228320 | +---------+ mysql> select * from JobMedia where JobId = 8208813\G *************************** 1. row *************************** JobMediaId: 6704362 JobId: 8208813 MediaId: 3205 FirstIndex: 1 LastIndex: 1 StartFile: 1 EndFile: 0 StartBlock: 4285650808 EndBlock: 0 VolIndex: 1 Stripe: 0 *************************** 2. row *************************** JobMediaId: 6704363 JobId: 8208813 MediaId: 3289 FirstIndex: 1 LastIndex: 1 StartFile: 0 EndFile: 0 StartBlock: 132125823 EndBlock: 132146970 VolIndex: 2 Stripe: 0 2 rows in set (0.00 sec) mysql> select * from JobMedia where JobId = 8208817\G *************************** 1. row *************************** JobMediaId: 6704358 JobId: 8208817 MediaId: 3205 FirstIndex: 1 LastIndex: 1 StartFile: 1 EndFile: 0 StartBlock: 4290489208 EndBlock: 0 VolIndex: 1 Stripe: 0 *************************** 2. row *************************** JobMediaId: 6704359 JobId: 8208817 MediaId: 3289 FirstIndex: 1 LastIndex: 1 StartFile: 0 EndFile: 0 StartBlock: 131993018 EndBlock: 131996798 VolIndex: 2 Stripe: 0 mysql> select * from JobMedia where JobId = 8228320\G *************************** 1. row *************************** JobMediaId: 6721875 JobId: 8228320 MediaId: 3348 FirstIndex: 1 LastIndex: 1 StartFile: 0 EndFile: 0 StartBlock: 258294 EndBlock: 307813 VolIndex: 2 Stripe: 0 *************************** 2. row *************************** JobMediaId: 6721874 JobId: 8228320 MediaId: 3399 FirstIndex: 1 LastIndex: 1 StartFile: 1 EndFile: 0 StartBlock: 4294788096 EndBlock: 0 VolIndex: 1 Stripe: 0 ---------------------------------------------------------------------- (0005955) bartosz.cisek (reporter) - 2011-08-26 10:43 http://bugs.bacula.org/view.php?id=1759#c5955 ---------------------------------------------------------------------- IMHO it has nothing in common with autochanger. Auto changer switches links between volumens, and reports 'vtape' status to bacula. It has nothing to do with writing wronk FileBlock to DB. ---------------------------------------------------------------------- (0005956) ebollengier (administrator) - 2011-08-26 11:10 http://bugs.bacula.org/view.php?id=1759#c5956 ---------------------------------------------------------------------- When you write "vtape", does it mean that you are using the vtape device type ? ---------------------------------------------------------------------- (0005957) bartosz.cisek (reporter) - 2011-08-26 11:26 http://bugs.bacula.org/view.php?id=1759#c5957 ---------------------------------------------------------------------- Each 'Device Type' is defined as 'File'. By 'vtape' I ment 'virtual type' as we use files to emulate tapes. Sorry for misleading. ---------------------------------------------------------------------- (0005958) ebollengier (administrator) - 2011-08-27 15:26 http://bugs.bacula.org/view.php?id=1759#c5958 ---------------------------------------------------------------------- Unless you provide us a simple way to reproduce the problem (how do you generate a backup with this kind of JobMedia records), we can't do anything. ---------------------------------------------------------------------- (0005959) kern (administrator) - 2011-08-27 17:42 http://bugs.bacula.org/view.php?id=1759#c5959 ---------------------------------------------------------------------- I agree with Eric. One thing that I requested was the Job Report of a job that created these bad records. I don't see that anywhere. Given that you have bad JobMedia records, no restore is going to work correctly, so all the restore output (given the bad records) looks perfectly normal. We are unable to reproduce this, and without being able to reproduce it or at least see the backup Job Report, there is nothing we can do. From the little I see, I would *guess* that you are running out of space on your device while Bacula is doing the backup, and in that process something is going wrong. ---------------------------------------------------------------------- (0005960) kern (administrator) - 2011-08-27 17:45 http://bugs.bacula.org/view.php?id=1759#c5960 ---------------------------------------------------------------------- Have you modified the source code? Where did you get your binaries or how did you create them? ---------------------------------------------------------------------- (0005961) bartosz.cisek (reporter) - 2011-08-29 10:32 http://bugs.bacula.org/view.php?id=1759#c5961 ---------------------------------------------------------------------- Our install is based on official bacula release (5.0.3). Compiled and pushed into Debian packages. I'll try to catch logs from creation of problematic jobs. Issue History Date Modified Username Field Change ====================================================================== 2011-08-17 12:12 bartosz.cisek New Issue 2011-08-17 13:11 ebollengier Note Added: 0005946 2011-08-17 13:11 ebollengier Assigned To => ebollengier 2011-08-17 13:11 ebollengier Status new => feedback 2011-08-18 07:46 kern Note Added: 0005947 2011-08-18 14:03 bartosz.cisek Note Added: 0005948 2011-08-18 14:03 bartosz.cisek Status feedback => assigned 2011-08-18 14:03 bartosz.cisek File Added: bacula-dir.conf 2011-08-18 14:04 bartosz.cisek File Added: bacula-sd.conf 2011-08-19 07:31 kern Note Added: 0005949 2011-08-19 07:31 kern Resolution open => unable to reproduce 2011-08-19 07:46 bartosz.cisek Note Added: 0005950 2011-08-19 16:59 kern Note Added: 0005951 2011-08-20 03:15 Dan Langille Note Added: 0005952 2011-08-25 10:35 bartosz.cisek Note Added: 0005953 2011-08-25 10:36 bartosz.cisek Note Added: 0005954 2011-08-26 10:43 bartosz.cisek Note Added: 0005955 2011-08-26 11:10 ebollengier Note Added: 0005956 2011-08-26 11:26 bartosz.cisek Note Added: 0005957 2011-08-27 15:26 ebollengier Note Added: 0005958 2011-08-27 17:42 kern Note Added: 0005959 2011-08-27 17:45 kern Note Added: 0005960 2011-08-27 17:45 kern Priority high => low 2011-08-27 17:45 kern Reproducibility always => unable to reproduce 2011-08-27 17:45 kern Status assigned => feedback 2011-08-27 17:45 kern Category btape => Storage Daemon 2011-08-29 10:32 bartosz.cisek Note Added: 0005961 2011-08-29 10:32 bartosz.cisek Status feedback => assigned ====================================================================== |