Hi! Kern Sibbald said: > Well, not having the *full* output from the job makes it a bit hard to > diagnose the problem. Normally, there should be additional output with > the > first error that was printed (affected_rows = 0). > > I have seen this kind of problem when a job is pruned while the job is > running. The job starts, creates a job database record, it is pruned, the > job terminates, and the job record no longer exist, hence the job fails as > in > the second error message above. This is possible and worth checking (i.e. > was anything pruned while the job ran?) but if you previously had database > problems, it is not very likely to be the cause.
I discovered this a couple of minutes before getting your reply. You're right, the job was pruned during the backup! Here's the complete output: 29-Jul 19:00 bacula-dir: Start Backup JobId 108, Job=Bang.2006-07-29_19.00.00 29-Jul 19:00 bacula-sd: Job Bang.2006-07-29_19.00.00 waiting to reserve a device. Something was wrong when the job started on Saturday evening, I can't remember exactly what I did to fix it yesterday, but I think I issued the mount/umount command. Thus the backup started 1.5 days later as expected... That was the reason for the pruning. Last week I changed the 'Volume Retention Period' for the tapes to 2 days. Because of the crash, I had to start the weekly backup on Thursday and the next full backup was scheduled for Saturday (I keep the full backups only one week at the moment, not the best way but I cant' change it) 31-Jul 09:43 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 31-Jul 09:43 bacula-sd: 3302 Autochanger "loaded drive 0", result: nothing loaded. 31-Jul 09:43 bacula-sd: 3304 Issuing autochanger "load slot 3, drive 0" command. 31-Jul 09:43 bacula-sd: 3305 Autochanger "load slot 3, drive 0", status is OK. 31-Jul 09:43 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 31-Jul 09:43 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 3. 31-Jul 09:44 bacula-sd: Recycled volume "Bang3" on device "AIT-2" (/dev/nst0), all previous data lost. 31-Jul 09:44 bacula-sd: Spooling data ... bang-fd: Filesystem change prohibited. Will not descend into /usr bang-fd: Filesystem change prohibited. Will not descend into /var bang-fd: Filesystem change prohibited. Will not descend into /local bang-fd: Filesystem change prohibited. Will not descend into /opt bang-fd: Filesystem change prohibited. Will not descend into /net bang-fd: Filesystem change prohibited. Will not descend into /export/home bang-fd: Filesystem change prohibited. Will not descend into /home bang-fd: Filesystem change prohibited. Will not descend into /server bang-fd: Filesystem change prohibited. Will not descend into /projekte bang-fd: Filesystem change prohibited. Will not descend into /public bang-fd: Filesystem change prohibited. Will not descend into /var/run 31-Jul 11:29 bacula-sd: User specified spool size reached. 31-Jul 11:29 bacula-sd: Writing spooled data to Volume. Despooling 37,580,970,177 bytes ... 31-Jul 12:51 bacula-sd: Spooling data again ... 31-Jul 13:57 bacula-sd: User specified spool size reached. 31-Jul 13:57 bacula-sd: Writing spooled data to Volume. Despooling 37,580,970,960 bytes ... 31-Jul 15:04 bacula-sd: End of Volume "Bang3" at 72:14798 on device "AIT-2" (/dev/nst0). Write of 64512 bytes got -1. 31-Jul 15:05 bacula-sd: Re-read of last block succeeded. 31-Jul 15:05 bacula-sd: End of medium on Volume "Bang3" Bytes=72,950,038,885 Blocks=1,130,798 at 31-Jul-2006 15:05. 31-Jul 15:06 bacula-dir: Recycled volume "Bang2" 31-Jul 15:06 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 31-Jul 15:06 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 3. 31-Jul 15:06 bacula-sd: 3307 Issuing autochanger "unload slot 3, drive 0" command. 31-Jul 15:07 bacula-sd: 3304 Issuing autochanger "load slot 2, drive 0" command. 31-Jul 15:07 bacula-sd: 3305 Autochanger "load slot 2, drive 0", status is OK. 31-Jul 15:07 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 31-Jul 15:07 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 2. 31-Jul 15:07 bacula-sd: Recycled volume "Bang2" on device "AIT-2" (/dev/nst0), all previous data lost. 31-Jul 15:07 bacula-sd: New volume "Bang2" mounted on device "AIT-2" (/dev/nst0) at 31-Jul-2006 15:07. 31-Jul 15:15 bacula-sd: Spooling data again ... 31-Jul 16:26 bacula-sd: User specified spool size reached. 31-Jul 16:26 bacula-sd: Writing spooled data to Volume. Despooling 37,580,970,939 bytes ... 31-Jul 17:55 bacula-sd: Spooling data again ... 31-Jul 19:04 bacula-sd: User specified spool size reached. 31-Jul 19:04 bacula-sd: Writing spooled data to Volume. Despooling 37,580,970,815 bytes ... 31-Jul 19:50 bacula-sd: End of Volume "Bang2" at 60:7190 on device "AIT-2" (/dev/nst0). Write of 64512 bytes got -1. 31-Jul 19:50 bacula-sd: Re-read of last block succeeded. 31-Jul 19:50 bacula-sd: End of medium on Volume "Bang2" Bytes=60,460,000,481 Blocks=937,190 at 31-Jul-2006 19:50. 31-Jul 19:51 bacula-dir: Recycled volume "Bang4" 31-Jul 19:51 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 31-Jul 19:51 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 2. 31-Jul 19:51 bacula-sd: 3307 Issuing autochanger "unload slot 2, drive 0" command. 31-Jul 19:52 bacula-sd: 3304 Issuing autochanger "load slot 4, drive 0" command. 31-Jul 19:52 bacula-sd: 3305 Autochanger "load slot 4, drive 0", status is OK. 31-Jul 19:52 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 31-Jul 19:52 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 4. 31-Jul 19:53 bacula-sd: Recycled volume "Bang4" on device "AIT-2" (/dev/nst0), all previous data lost. 31-Jul 19:53 bacula-sd: New volume "Bang4" mounted on device "AIT-2" (/dev/nst0) at 31-Jul-2006 19:53. 31-Jul 20:27 bacula-sd: Spooling data again ... 31-Jul 21:54 bacula-sd: User specified spool size reached. 31-Jul 21:54 bacula-sd: Writing spooled data to Volume. Despooling 37,580,970,259 bytes ... 31-Jul 23:20 bacula-sd: Spooling data again ... 01-Aug 00:57 bacula-sd: User specified spool size reached. 01-Aug 00:57 bacula-sd: Writing spooled data to Volume. Despooling 37,580,970,269 bytes ... 01-Aug 01:31 bacula-sd: End of Volume "Bang4" at 71:7267 on device "AIT-2" (/dev/nst0). Write of 64512 bytes got -1. 01-Aug 01:31 bacula-sd: Re-read of last block succeeded. 01-Aug 01:31 bacula-sd: End of medium on Volume "Bang4" Bytes=71,464,262,810 Blocks=1,107,767 at 01-Aug-2006 01:31. 01-Aug 01:33 bacula-dir: There are no Jobs associated with Volume "Bang1". Marking it purged. 01-Aug 01:33 bacula-dir: Pruned 1 Job on Volume "Bang3" from catalog. 01-Aug 01:33 bacula-dir: There are no Jobs associated with Volume "Bang2". Marking it purged. 01-Aug 01:33 bacula-dir: There are no Jobs associated with Volume "Bang4". Marking it purged. 01-Aug 01:33 bacula-dir: Recycled volume "Bang1" 01-Aug 01:33 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 01-Aug 01:33 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 4. 01-Aug 01:33 bacula-sd: 3307 Issuing autochanger "unload slot 4, drive 0" command. 01-Aug 01:33 bacula-sd: 3304 Issuing autochanger "load slot 1, drive 0" command. 01-Aug 01:34 bacula-sd: 3305 Autochanger "load slot 1, drive 0", status is OK. 01-Aug 01:34 bacula-sd: 3301 Issuing autochanger "loaded drive 0" command. 01-Aug 01:34 bacula-sd: 3302 Autochanger "loaded drive 0", result is Slot 1. 01-Aug 01:34 bacula-sd: Recycled volume "Bang1" on device "AIT-2" (/dev/nst0), all previous data lost. 01-Aug 01:34 bacula-sd: New volume "Bang1" mounted on device "AIT-2" (/dev/nst0) at 01-Aug-2006 01:34. 01-Aug 02:19 bacula-sd: Spooling data again ... 01-Aug 02:21 bacula-sd: Committing spooled data to Volume "Bang1". Despooling 908,909,975 bytes ... 01-Aug 02:23 bacula-dir: Max configured use duration exceeded. Marking Volume "Bang1" as Used. 01-Aug 02:23 bacula-sd: Sending spooled attrs to the Director. Despooling 241,550,790 bytes ... 01-Aug 03:55 bacula-dir: Bang.2006-07-29_19.00.00 Warning: Error updating job record. sql_update.c:169 Update problem: affected_rows=0 01-Aug 03:55 bacula-dir: Bang.2006-07-29_19.00.00 Warning: Error getting job record for stats: sql_get.c:287 No Job found for JobId 108 01-Aug 03:55 bacula-dir: Bang.2006-07-29_19.00.00 Error: Bacula 1.38.5 (18Jan06): 01-Aug-2006 03:55:29 >> It seems that I still have a db problem. What can I look for and how can >> I fix it? Any ideas? > > Here again, you didn't show provide all the information -- most > importantly > did you run dbcheck so that it would correct those errors? It will not by > default modify the database. Until you run it and let it modify the > database, the inconsistencies will remain. This time I didn't run dbcheck with the fix option, last week as I had to restore the bacula.sql backup, I did. I'm glad that todays problem was not because of a inconsistent database! Ralf ------------------------------------------------------------------------- Take Surveys. Earn Cash. Influence the Future of IT Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys -- and earn cash http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV _______________________________________________ Bacula-users mailing list Bacula-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/bacula-users
