On Wednesday 29 March 2006 16:25, Kern Sibbald wrote: > What I would like to see is: the output showing how job messages are > intermixed. I don't need the whole log, but if you clip stuff out here and > there, it won't help me understand the problem.
OK, I've attached my director conf and the messages from syslog. What the log doesn't show (and I tried to describe) is that the jobs that later got cancelled were scheduled and run at the appropriate time (at 17:30), but had to wait because the job I started at Mar 27, 11:47 (first log line) still was running. I think the jobs "full.2006-03-27_17.30.00", "catalog.2006-03-27_17.30.01" and "closing.2006-03-27_17.30.02" should all have been cancelled on the 28th, 15:30 (17:30 + timeout of 22 hours). MfG, Ulrich -- Heinz Ulrich Stille / Tel.: +49-541-9400473 / Fax: +49-541-9400450 design_d gmbh / Wilhelmstr. 16 / 49076 Osnabrück / www.design-d.de
Director { Name = mail-dir DIRAddress = 192.168.1.1 DIRport = 9101 QueryFile = "/opt/packages/collect/libexec/bacula/query.sql" WorkingDirectory = "/var/bacula/working" PidDirectory = "/var/run" Maximum Concurrent Jobs = 1 Password = "***" Messages = Daemon } JobDefs { Name = "DefaultJob" Type = Backup Level = Incremental Client = mail-fd Storage = Tape Messages = Standard Pool = Daily FileSet = "full" Priority = 10 Max Start Delay = 22 hours } Job { Name = "full" JobDefs = "DefaultJob" FileSet = "full" Schedule = "Weekly" Write Bootstrap = "/var/bacula/working/full.bsr" } Job { Name = "catalog" JobDefs = "DefaultJob" FileSet="Catalog" Schedule = "Weekly" RunBeforeJob = "/opt/packages/collect/libexec/bacula/make_catalog_backup bacula bacula" RunAfterJob = "/opt/packages/collect/libexec/bacula/delete_catalog_backup" Write Bootstrap = "/var/bacula/working/BackupCatalog.bsr" Priority = 50 } Job { Name = "closing" JobDefs = "DefaultJob" Type = Admin Priority = 99 Schedule = "Weekly" RunAfterJob = "/bin/mt -f /dev/nst0 rewoffl" } FileSet { Name = "full" Include { Options { signature = MD5; onefs = yes } File = / File = /var } Include { Options { signature = MD5; onefs = yes } Options { wild = ".*"; exclude = yes } File = /export/taos/admin File = /export/taos/app File = /export/taos/dat File = /export/taos/fin } Exclude { File = /tmp File = /var/tmp File = /opt/packages/source File = /var/bacula File = /var/cache } } FileSet { Name = "Catalog" Include { Options { signature = MD5 } File = /var/bacula/working/bacula.sql } } Schedule { Name = "Weekly" Run = Full Pool=Weekly fri at 15:30 Run = Incremental Pool=Daily mon-thu at 17:30 } Client { Name = mail-fd Address = 192.168.1.1 FDPort = 9102 Catalog = tammen Password = "***" File Retention = 30 days Job Retention = 6 months AutoPrune = yes } Storage { Name = Tape Address = 192.168.1.1 SDPort = 9103 Password = "***" Device = DLT Media Type = DLT-8000 } Catalog { Name = tammen dbname = bacula; user = bacula; password = "" } Messages { Name = Standard mailcommand = "/opt/packages/collect/sbin/bsmtp -h localhost -f \"\(Bacula\) %r\" -s \"Bacula: %t %e of %c %l\" %r" operatorcommand = "/opt/packages/collect/sbin/bsmtp -h localhost -f \"\(Bacula\) %r\" -s \"Bacula: Intervention needed for %j\" %r" mail = [EMAIL PROTECTED] = all, !skipped operator = [EMAIL PROTECTED] = mount console = all, !skipped, !saved syslog = all, !skipped, !saved } Messages { Name = Daemon mailcommand = "/opt/packages/collect/sbin/bsmtp -h localhost -f \"\(Bacula\) %r\" -s \"Bacula daemon message\" %r" mail = [EMAIL PROTECTED] = all, !skipped operator = [EMAIL PROTECTED] = mount console = all, !skipped, !saved syslog = all, !skipped, !saved } Pool { Name = Weekly Pool Type = Backup Recycle = yes AutoPrune = yes Volume Retention = 10 days } Pool { Name = Daily Pool Type = Backup Recycle = yes AutoPrune = yes Volume Retention = 6 days Volume Use Duration = 23 hours }
Mar 27 11:47:04 mail bacula-dir: mail-dir: Start Backup JobId 3, Job=full.2006-03-27_11.47.02 Mar 27 11:47:11 mail bacula-dir: mail-sd: full.2006-03-27_11.47.02 Warning: Director wanted Volume "w02". Current Volume "Mo" not acceptable because: 1998 Volume "Mo" status is Append, not in Pool. Mar 27 11:47:13 mail bacula-dir: mail-sd: Please mount Volume "w02" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 27 11:59:24 mail bacula-dir: mail-dir: Recycled current volume "w01" Mar 27 11:59:25 mail bacula-dir: mail-sd: Recycled volume "w01" on device "DLT" (/dev/nst0), all previous data lost. Mar 27 12:31:06 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /dev Mar 27 13:35:47 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /sysfs Mar 27 13:43:41 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /proc Mar 27 14:10:04 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /var Mar 27 14:10:04 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /export Mar 27 14:10:04 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /sys Mar 27 14:13:04 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /var/lib/nfs/rpc_pipefs Mar 27 14:52:05 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /var/named/chroot/proc Mar 27 15:59:18 mail bacula-dir: mail-sd: End of Volume "w01" at 46:10244 on device "DLT" (/dev/nst0). Write of 64512 bytes got -1. Mar 27 16:00:06 mail bacula-dir: mail-sd: Re-read of last block succeeded. Mar 27 16:00:06 mail bacula-dir: mail-sd: End of medium on Volume "w01" Bytes=46,657,914,977 Blocks=723,244 at 27-Mar-2006 16:00. Mar 27 16:00:21 mail bacula-dir: mail-sd: Please mount Volume "w02" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 27 16:01:25 mail bacula-dir: mail-sd: full.2006-03-27_11.47.02 Warning: Director wanted Volume "w02". Current Volume "w01" not acceptable because: 1998 Volume "w01" status is Full, but should be Append, Purged or Recycle. Mar 27 16:26:28 mail bacula-dir: mail-sd: Wrote label to prelabeled Volume "w02" on device "DLT" (/dev/nst0) Mar 27 16:26:28 mail bacula-dir: mail-sd: New volume "w02" mounted on device "DLT" (/dev/nst0) at 27-Mar-2006 16:26. Mar 27 20:11:28 mail bacula-dir: mail-sd: End of Volume "w02" at 45:433 on device "DLT" (/dev/nst0). Write of 64512 bytes got -1. Mar 27 20:13:19 mail bacula-dir: mail-sd: Re-read of last block succeeded. Mar 27 20:13:19 mail bacula-dir: mail-sd: End of medium on Volume "w02" Bytes=45,025,052,675 Blocks=697,933 at 27-Mar-2006 20:13. Mar 27 20:13:33 mail bacula-dir: mail-sd: Please mount Volume "w03" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 27 20:14:37 mail bacula-dir: mail-sd: full.2006-03-27_11.47.02 Warning: Director wanted Volume "w03". Current Volume "w02" not acceptable because: 1998 Volume "w02" status is Full, but should be Append, Purged or Recycle. Mar 27 21:09:15 mail bacula-dir: mail-sd: Wrote label to prelabeled Volume "w03" on device "DLT" (/dev/nst0) Mar 27 21:09:15 mail bacula-dir: mail-sd: New volume "w03" mounted on device "DLT" (/dev/nst0) at 27-Mar-2006 21:09. Mar 28 00:25:23 mail bacula-dir: mail-sd: End of Volume "w03" at 44:10286 on device "DLT" (/dev/nst0). Write of 64512 bytes got -1. Mar 28 00:26:13 mail bacula-dir: mail-sd: Re-read of last block succeeded. Mar 28 00:26:13 mail bacula-dir: mail-sd: End of medium on Volume "w03" Bytes=44,660,753,565 Blocks=692,286 at 28-Mar-2006 00:26. Mar 28 00:26:28 mail bacula-dir: mail-sd: Please mount Volume "w04" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 28 00:27:31 mail bacula-dir: mail-sd: full.2006-03-27_11.47.02 Warning: Director wanted Volume "w04". Current Volume "w03" not acceptable because: 1998 Volume "w03" status is Full, but should be Append, Purged or Recycle. Mar 28 01:31:52 mail bacula-dir: mail-sd: Please mount Volume "w04" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 28 03:42:46 mail bacula-dir: mail-sd: Please mount Volume "w04" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 28 08:04:48 mail bacula-dir: mail-sd: Please mount Volume "w04" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-27_11.47.02 Mar 28 08:21:10 mail bacula-dir: mail-sd: Wrote label to prelabeled Volume "w04" on device "DLT" (/dev/nst0) Mar 28 08:21:10 mail bacula-dir: mail-sd: New volume "w04" mounted on device "DLT" (/dev/nst0) at 28-Mar-2006 08:21. Mar 28 17:34:16 mail bacula-dir: mail-dir: Bacula 1.38.5 (18Jan06): 28-Mar-2006 17:34:15 JobId: 3 Job: full.2006-03-27_11.47.02 Backup Level: Full Client: "mail-fd" i686-pc-linux-gnu,redhat,(Rawhide) FileSet: "full" 2006-03-26 00:53:58 Pool: "Weekly" Storage: "Tape" Scheduled time: 27-Mar-2006 11:46:40 Start time: 27-Mar-2006 11:47:04 End time: 28-Mar-2006 17:34:15 Priority: 10 FD Files Written: 803,049 SD Files Written: 803,049 FD Bytes Written: 172,003,756,473 SD Bytes Written: 172,116,756,062 Rate: 1604.0 KB/s Software Compression: None Volume name(s): w01|w02|w03|w04 Volume Session Id: 3 Volume Session Time: 1143310217 Last Volume Bytes: 35,923,416,643 Non-fatal FD errors: 0 SD Errors: 0 FD termination status: OK SD ter Mar 28 17:34:16 mail bacula-dir: mail-dir: Begin pruning Jobs. Mar 28 17:34:16 mail bacula-dir: mail-dir: No Jobs found to prune. Mar 28 17:34:16 mail bacula-dir: mail-dir: Begin pruning Files. Mar 28 17:34:16 mail bacula-dir: mail-dir: No Files found to prune. Mar 28 17:34:16 mail bacula-dir: mail-dir: End auto prune. Mar 28 17:34:22 mail bacula-dir: mail-dir: full.2006-03-27_17.30.00 Fatal error: Job canceled because max start delay time exceeded. Mar 28 17:34:25 mail bacula-dir: mail-dir: Start Backup JobId 7, Job=full.2006-03-28_17.30.00 Mar 28 17:34:33 mail bacula-dir: mail-sd: full.2006-03-28_17.30.00 Warning: Director wanted Volume "Mo". Current Volume "w04" not acceptable because: 1998 Volume "w04" status is Append, not in Pool. Mar 28 17:34:34 mail bacula-dir: mail-sd: Please mount Volume "Mo" on Storage Device "DLT" (/dev/nst0) for Job full.2006-03-28_17.30.00 Mar 28 18:32:44 mail bacula-dir: mail-sd: Wrote label to prelabeled Volume "Mo" on device "DLT" (/dev/nst0) Mar 28 18:34:26 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /dev Mar 28 18:35:03 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /sysfs Mar 28 18:36:08 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /proc Mar 28 18:39:32 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /var Mar 28 18:39:32 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /export Mar 28 18:39:32 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /sys Mar 28 18:39:34 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /var/lib/nfs/rpc_pipefs Mar 28 18:56:53 mail bacula-dir: mail-fd: Filesystem change prohibited. Will not descend into /var/named/chroot/proc Mar 28 19:16:02 mail bacula-dir: mail-dir: Bacula 1.38.5 (18Jan06): 28-Mar-2006 19:16:02 JobId: 7 Job: full.2006-03-28_17.30.00 Backup Level: Incremental, since=2006-03-27 11:47:04 Client: "mail-fd" i686-pc-linux-gnu,redhat,(Rawhide) FileSet: "full" 2006-03-26 00:53:58 Pool: "Daily" Storage: "Tape" Scheduled time: 28-Mar-2006 17:30:00 Start time: 28-Mar-2006 17:34:25 End time: 28-Mar-2006 19:16:02 Priority: 10 FD Files Written: 9,788 SD Files Written: 9,788 FD Bytes Written: 5,295,056,880 SD Bytes Written: 5,296,341,639 Rate: 868.5 KB/s Software Compression: None Volume name(s): Mo Volume Session Id: 4 Volume Session Time: 1143310217 Last Volume Bytes: 5,300,566,960 Non-fatal FD errors: 0 SD Errors: 0 FD termination status: O Mar 28 19:16:02 mail bacula-dir: mail-dir: Begin pruning Jobs. Mar 28 19:16:02 mail bacula-dir: mail-dir: No Jobs found to prune. Mar 28 19:16:02 mail bacula-dir: mail-dir: Begin pruning Files. Mar 28 19:16:02 mail bacula-dir: mail-dir: No Files found to prune. Mar 28 19:16:02 mail bacula-dir: mail-dir: End auto prune. Mar 28 19:16:06 mail bacula-dir: mail-dir: catalog.2006-03-27_17.30.01 Fatal error: Job canceled because max start delay time exceeded. Mar 28 19:16:06 mail bacula-dir: mail-dir: No prior Full backup Job record found. Mar 28 19:16:06 mail bacula-dir: mail-dir: No prior or suitable Full backup found. Doing FULL backup. Mar 28 19:16:10 mail bacula-dir: mail-dir: No prior Full backup Job record found. Mar 28 19:16:10 mail bacula-dir: mail-dir: No prior or suitable Full backup found. Doing FULL backup. Mar 28 19:16:26 mail bacula-dir: mail-dir: Start Backup JobId 8, Job=catalog.2006-03-28_17.30.01 Mar 28 19:16:33 mail bacula-dir: mail-sd: Volume "Mo" previously written, moving to end of data. Mar 28 19:17:24 mail bacula-dir: mail-sd: Ready to append to end of Volume "Mo" at file=6. Mar 28 19:18:45 mail bacula-dir: mail-dir: Bacula 1.38.5 (18Jan06): 28-Mar-2006 19:18:45 JobId: 8 Job: catalog.2006-03-28_17.30.01 Backup Level: Full (upgraded from Incremental) Client: "mail-fd" i686-pc-linux-gnu,redhat,(Rawhide) FileSet: "Catalog" 2006-03-28 19:16:06 Pool: "Daily" Storage: "Tape" Scheduled time: 28-Mar-2006 17:30:00 Start time: 28-Mar-2006 19:16:10 End time: 28-Mar-2006 19:18:45 Priority: 50 FD Files Written: 1 SD Files Written: 1 FD Bytes Written: 101,405,753 SD Bytes Written: 101,405,868 Rate: 654.2 KB/s Software Compression: None Volume name(s): Mo Volume Session Id: 5 Volume Session Time: 1143310217 Last Volume Bytes: 5,402,048,422 Non-fatal FD errors: 0 SD Errors: 0 FD termination status: OK SD termi Mar 28 19:18:45 mail bacula-dir: mail-dir: Begin pruning Jobs. Mar 28 19:18:45 mail bacula-dir: mail-dir: No Jobs found to prune. Mar 28 19:18:45 mail bacula-dir: mail-dir: Begin pruning Files. Mar 28 19:18:45 mail bacula-dir: mail-dir: No Files found to prune. Mar 28 19:18:45 mail bacula-dir: mail-dir: End auto prune. Mar 28 19:18:48 mail bacula-dir: mail-dir: closing.2006-03-27_17.30.02 Fatal error: Job canceled because max start delay time exceeded. Mar 28 19:18:51 mail bacula-dir: mail-dir: Start Admin JobId 9, Job=closing.2006-03-28_17.30.02 Mar 28 19:18:51 mail bacula-dir: mail-dir: Bacula 1.38.5 (18Jan06): 28-Mar-2006 19:18 JobId: 9 Job: closing.2006-03-28_17.30.02 Start time: 28-Mar-2006 19:18 End time: 28-Mar-2006 19:18 Termination: Admin OK Mar 28 19:18:51 mail bacula-dir: mail-dir: Begin pruning Jobs. Mar 28 19:18:51 mail bacula-dir: mail-dir: No Jobs found to prune. Mar 28 19:18:51 mail bacula-dir: mail-dir: Begin pruning Files. Mar 28 19:18:51 mail bacula-dir: mail-dir: No Files found to prune. Mar 28 19:18:51 mail bacula-dir: mail-dir: End auto prune.