Hello,
Maybe the SD crashed or something and there is an old spool file that is in
your spool directory that should have been deleted.
Under 1.37, I have "unified" the naming convention of all Bacula temporary
files so that it will be easy to know which ones are used for what (the use
is always postfixed -- e.g. .spool, .mail, ...) and it will be easier to do
spool/working directory cleanup from time to time.
This is also an item that remains to be documented for 1.38
On Thursday 25 August 2005 14:28, Kristian Ejvind wrote:
> Hi.
>
> In my small home network I use bacula on a Solaris 9 box to back up three
> computers. Bacula spools data to local disk in 2 GB chunks before writing
> to tape, and it has been humming along nicely for a year or so. Suddenly, a
> couple of weeks ago, it started to spool less than configured, only about
> 260 MB. There's plenty of space available on the spool disk.
>
> Not a big problem really for me, but I thought it could be interesting for
> someone out there? I havn't tried to solve this problem yet, but will do
> unless someone wants more info from me.
>
> Server: solaris 9 with bacula 1.36.1 and one DLT8000 tape, this is from
> bacula- sd.conf:
>
> Device {
> Name = DLT1 #
> Media Type = DLT8000
> Archive Device = /dev/rmt/0cbn
> AutomaticMount = yes # when device opened, read it
> AlwaysOpen = yes
> RemovableMedia = yes
> RandomAccess = no
> MaximumSpoolSize = 2G
> SpoolDirectory = "/opt/packages/bacula/data/spool"
> OfflineOnUnmount = yes
> }
>
>
> These examples are from a backup of a windows machine, but
> the same happens when the bacula server backs up itself.
>
> A completion report. Notice that it says "despooling 2G" 21 times, but "SD
> bytes written" is only 5GB (which is correct)
>
>
> ----------------------------------------------
> 24-Aug 09:46 aron-dir: Start Backup JobId 1040, Job=Alf.2005-08-24_07.07.00
> 24-Aug 09:46 aron-sd: Spooling data ...
> 24-Aug 09:49 alf-fd: Cannot open C:/Program
> Files/Canon/MultiPASS/repos/Db/mpdata.dat: ERR=The process cannot access
> the file because it is being used by another process.
> .
> 24-Aug 09:49 alf-fd: Cannot open C:/Program
> Files/Canon/MultiPASS/repos/Db/mpdata.idx: ERR=The process cannot access
> the file because it is being used by another process.
> .
> 24-Aug 09:49 aron-sd: User specified spool size reached.
> 24-Aug 09:49 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,926 bytes ...
> 24-Aug 09:50 aron-sd: Spooling data again ...
> 24-Aug 09:52 aron-sd: User specified spool size reached.
> 24-Aug 09:52 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,905 bytes ...
> 24-Aug 09:52 aron-sd: Spooling data again ...
> 24-Aug 09:54 aron-sd: User specified spool size reached.
> 24-Aug 09:54 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,924 bytes ...
> 24-Aug 09:55 aron-sd: End of Volume "Diff-0006" at 58:10738 on device
> /dev/rmt/0cbn. Write of 64512 bytes got 0.
> 24-Aug 09:56 aron-sd: Re-read of last block succeeded.
> 24-Aug 09:56 aron-sd: End of medium on Volume "Diff-0006"
> Bytes=54,005,158,759 Blocks=837,139 at 24-Aug-2005 09:56.
> 24-Aug 09:56 aron-dir: Recycled volume "Diff-0007"
> 24-Aug 09:56 aron-sd: Please mount Volume "Diff-0007" on Storage Device
> "DLT1" for Job Alf.2005-08-24_07.07.00
> 24-Aug 10:56 aron-sd: Please mount Volume "Diff-0007" on Storage Device
> "DLT1" for Job Alf.2005-08-24_07.07.00
> 24-Aug 11:33 aron-sd: Recycled volume "Diff-0007" on device
> "/dev/rmt/0cbn", all previous data lost.
> 24-Aug 11:33 aron-sd: New volume "Diff-0007" mounted on device
> /dev/rmt/0cbn at 24-Aug-2005 11:33.
> 24-Aug 11:33 aron-sd: Spooling data again ...
> 24-Aug 11:35 aron-sd: User specified spool size reached.
> 24-Aug 11:35 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,909 bytes ...
> 24-Aug 11:36 aron-sd: Spooling data again ...
> 24-Aug 11:37 aron-sd: User specified spool size reached.
> 24-Aug 11:37 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,922 bytes ...
> 24-Aug 11:38 aron-sd: Spooling data again ...
> 24-Aug 11:39 aron-sd: User specified spool size reached.
> 24-Aug 11:39 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,926 bytes ...
> 24-Aug 11:41 aron-sd: Spooling data again ...
> 24-Aug 11:42 aron-sd: User specified spool size reached.
> 24-Aug 11:42 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,897 bytes ...
> 24-Aug 11:43 aron-sd: Spooling data again ...
> 24-Aug 11:44 aron-sd: User specified spool size reached.
> 24-Aug 11:44 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,878 bytes ...
> 24-Aug 11:45 aron-sd: Spooling data again ...
> 24-Aug 11:46 aron-sd: User specified spool size reached.
> 24-Aug 11:46 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,884 bytes ...
> 24-Aug 11:47 aron-sd: Spooling data again ...
> 24-Aug 11:47 aron-sd: User specified spool size reached.
> 24-Aug 11:47 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,886 bytes ...
> 24-Aug 11:48 aron-sd: Spooling data again ...
> 24-Aug 11:49 aron-sd: User specified spool size reached.
> 24-Aug 11:49 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,888 bytes ...
> 24-Aug 11:50 aron-sd: Spooling data again ...
> 24-Aug 11:51 aron-sd: User specified spool size reached.
> 24-Aug 11:51 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,878 bytes ...
> 24-Aug 11:52 aron-sd: Spooling data again ...
> 24-Aug 11:53 aron-sd: User specified spool size reached.
> 24-Aug 11:53 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,878 bytes ...
> 24-Aug 11:54 aron-sd: Spooling data again ...
> 24-Aug 11:55 aron-sd: User specified spool size reached.
> 24-Aug 11:55 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,886 bytes ...
> 24-Aug 11:56 aron-sd: Spooling data again ...
> 24-Aug 11:57 aron-sd: User specified spool size reached.
> 24-Aug 11:57 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,902 bytes ...
> 24-Aug 11:58 aron-sd: Spooling data again ...
> 24-Aug 11:59 aron-sd: User specified spool size reached.
> 24-Aug 11:59 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,901 bytes ...
> 24-Aug 12:00 aron-sd: Spooling data again ...
> 24-Aug 12:01 aron-sd: User specified spool size reached.
> 24-Aug 12:01 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,886 bytes ...
> 24-Aug 12:02 aron-sd: Spooling data again ...
> 24-Aug 12:03 aron-sd: User specified spool size reached.
> 24-Aug 12:03 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,878 bytes ...
> 24-Aug 12:04 aron-sd: Spooling data again ...
> 24-Aug 12:05 aron-sd: User specified spool size reached.
> 24-Aug 12:05 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,886 bytes ...
> 24-Aug 12:06 aron-sd: Spooling data again ...
> 24-Aug 12:07 aron-sd: User specified spool size reached.
> 24-Aug 12:07 aron-sd: Writing spooled data to Volume. Despooling
> 2,147,497,893 bytes ...
> 24-Aug 12:08 aron-sd: Spooling data again ...
> 24-Aug 12:09 aron-sd: Committing spooled data to Volume. Despooling
> 2,050,419,334 bytes ...
> 24-Aug 12:10 aron-sd: Sending spooled attrs to the Director. Despooling
> 2,586,536 bytes ...
> 24-Aug 12:11 aron-dir: Bacula 1.36.1 (26Nov04): 24-Aug-2005 12:11:00
> JobId: 1040
> Job: Alf.2005-08-24_07.07.00
> Backup Level: Differential, since=2005-03-16 21:16:40
> Client: alf-fd
> FileSet: "Alf Files" 2004-12-19 18:24:41
> Pool: "Diff"
> Storage: "DLT1"
> Start time: 24-Aug-2005 09:46:45
> End time: 24-Aug-2005 12:11:00
> FD Files Written: 7,974
> SD Files Written: 7,974
> FD Bytes Written: 5,572,580,207
> SD Bytes Written: 5,573,990,439
> Rate: 643.9 KB/s
> Software Compression: None
> Volume name(s): Diff-0006|Diff-0007
> Volume Session Id: 81
> Volume Session Time: 1123050581
> Last Volume Bytes: 4,886,684,427
> Non-fatal FD errors: 2
> SD Errors: 0
> FD termination status: OK
> SD termination status: OK
> Termination: Backup OK -- with warnings
>
> 24-Aug 12:11 aron-dir: Begin pruning Jobs.
> 24-Aug 12:11 aron-dir: Pruned 1 Job for client alf-fd from catalog.
> 24-Aug 12:11 aron-dir: Begin pruning Files.
> 24-Aug 12:11 aron-dir: Pruned 5,877 Files from 1 Jobs for client alf-fd
> from catalog.
> 24-Aug 12:11 aron-dir: End auto prune.
>
> ----------------------------------------------------------
>
>
>
> while the backup was running, I truss'ed bacula-sd:
>
>
>
> ----------------------------------------------------------
>
> /161: read(7, " t M x q E8F , BE1E0 QE9".., 32768) = 32768
> /161: read(7, "\0\080\0", 4) = 4
> /161: read(7, "ACA018 5 yF697 [B0D29993".., 32768) = 32768
> /161: write(8, "\0\01F12\0\01F12\0\0FC\0", 12) = 12
> /161: write(8, " U U U U U U U U U U U U".., 64512) = 64512
> /161: read(7, "\0\080\0", 4) = 4
> /161: read(7, "C3 # B + p YD7FF ' R =C2".., 32768) = 32768
> /161: read(7, "\0\080\0", 4) = 4
> /161: read(7, "EDD202EBE5 t8BF0BCBBD6 Z".., 32768) = 32768
> /161: write(8, "\0\01F12\0\01F12\0\0FC\0", 12) = 12
> /161: write(8, " U U U U U U U U U U U U".., 64512) = 64512
> /161: read(7, "\0\080\0", 4) = 4
> /161: read(7, "C9 xB2 G9ED3 a k ' 6 x g".., 32768) = 32768
> /161: read(7, "\0\080\0", 4) = 4
> /161: read(7, "D7 BC r ; yF785F71B\n \".., 32768) = 32768
> /161: time() = 1124876980
> /161: write(6, "\0\0\0 e", 4) = 4
> /161: write(6, 0x000733F0, 101) = 101
> /161: J m s g J o b = A l f . 2 0 0 5 - 0 8 - 2 4 _ 0 7 . 0 7 . 0 0
> /161: t y p e = 6 l e v e l = 1 1 2 4 8 7 6 9 8 0 a r o n - s d
> /161: : U s e r s p e c i f i e d s p o o l s i z e r e a c
> /161: h e d .\n
> /161: time() = 1124876980
> /161: write(6, "\0\0\085", 4) = 4
> /161: write(6, 0x000733F0, 133) = 133
> /161: J m s g J o b = A l f . 2 0 0 5 - 0 8 - 2 4 _ 0 7 . 0 7 . 0 0
> /161: t y p e = 6 l e v e l = 1 1 2 4 8 7 6 9 8 0 a r o n - s d
> /161: : W r i t i n g s p o o l e d d a t a t o V o l u m e
> /161: . D e s p o o l i n g 2 , 1 4 7 , 4 9 7 , 8 8 8 b y t e s
> /161: . . .\n
> /161: llseek(8, 0, SEEK_SET) = 0
> /161: read(8, "\0\01F10\0\01F10\0\0FC\0", 12) = 12
> /161: read(8, " U U U U U U U U U U U U".., 64512) = 64512
> /161: write(3, " ADEBD9E\0\0FC\0\0\0\0\0".., 64512) = 64512
> /161: read(8, "\0\01F10\0\01F10\0\0FC\0", 12) = 12
> /161: read(8, " U U U U U U U U U U U U".., 64512) = 64512
> /161: write(3, "9B\012EE\0\0FC\0\0\0\001".., 64512) = 64512
> /161: read(8, "\0\01F10\0\01F10\0\0FC\0", 12) = 12
> /161: read(8, " U U U U U U U U U U U U".., 64512) = 64512
> /161: write(3, " N PDDF9\0\0FC\0\0\0\002".., 64512) = 64512
> /161: read(8, "\0\01F10\0\01F10\0\0FC\0", 12) = 12
> /161: read(8, " U U U U U U U U U U U U".., 64512) = 64512
> /161: write(3, "DDF9EE U\0\0FC\0\0\0\003".., 64512) = 64512
> /161: read(8, "\0\01F10\0\01F10\0\0FC\0", 12) = 12
>
> ----------------------------------------------------------------
>
>
>
> and lastly, a few commands from when the backup was running.
>
>
>
> ----------------------------------------------------------------
> # ll
> total 528336
> -rw-r----- 1 root root 270355520 Aug 19 20:17 aron-
> sd.data.spool.Alf.2005-08-19_07.07.00.DLT1
>
> # df -k
> Filesystem kbytes used avail capacity Mounted on
> /dev/md/dsk/d0 5041230 4018076 972742 81% /
> /proc 0 0 0 0% /proc
> mnttab 0 0 0 0% /etc/mnttab
> fd 0 0 0 0% /dev/fd
> /dev/md/dsk/d3 577391 269110 250542 52% /var
> swap 459888 56 459832 1% /var/run
> swap 489536 29704 459832 7% /tmp
> /dev/md/dsk/d4 110004472 38612674 70291754 36% /.d4
>
> # ll
> total 528336
> -rw-r----- 1 root root 270355520 Aug 19 20:17 aron-
> sd.data.spool.Alf.2005-08-19_07.07.00.DLT1
>
> # du -h
> 258M .
>
> # df -k .
> Filesystem kbytes used avail capacity Mounted on
> /dev/md/dsk/d4 110004472 38612674 70291754 36% /.d4
>
> #
> # pwd
> /opt/packages/bacula/data/spool
>
> # ll
> total 528336
> -rw-r----- 1 root root 270355543 Aug 24 11:35 aron-
> sd.data.spool.Alf.2005-08-24_07.07.00.DLT1
>
> # df -k .
> Filesystem kbytes used avail capacity Mounted on
> /dev/md/dsk/d4 110004472 38862174 70042254 36% /.d4
>
> # du
> 258M .
>
> # ll
> total 88160
> -rw-r----- 1 root root 45102276 Aug 24 11:36 aron-
> sd.data.spool.Alf.2005-08-24_07.07.00.DLT1
>
> # ll
> total 528336
> -rw-r----- 1 root root 270355556 Aug 24 11:37
> aron-sd.data.spool.Alf.2005-08-24_07.07.00.DLT1
>
> # df -h .
> Filesystem size used avail capacity Mounted on
> /dev/md/dsk/d4 105G 37G 67G 36% /.d4
>
> # ll
> total 528336
> -rw-r----- 1 root root 270355560 Aug 24 11:39 aron-
> sd.data.spool.Alf.2005-08-24_07.07.00.DLT1
>
> # ll
> total 528336
> -rw-r----- 1 root root 270355531 Aug 24 11:42 aron-
> sd.data.spool.Alf.2005-08-24_07.07.00.DLT1
>
> # df -h .
> Filesystem size used avail capacity Mounted on
> /dev/md/dsk/d4 105G 37G 67G 36% /.d4
>
> # ll
> total 528336
> -rw-r----- 1 root root 270355512 Aug 24 11:44
> aron-sd.data.spool.Alf.2005-08-24_07.07.00.DLT1
>
>
>
> -------------------------------------------------------
> SF.Net email is Sponsored by the Better Software Conference & EXPO
> September 19-22, 2005 * San Francisco, CA * Development Lifecycle Practices
> Agile & Plan-Driven Development * Managing Projects & Teams * Testing & QA
> Security * Process Improvement & Measurement * http://www.sqe.com/bsce5sf
> _______________________________________________
> Bacula-users mailing list
> Bacula-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
--
Best regards,
Kern
(">
/\
V_V
-------------------------------------------------------
SF.Net email is Sponsored by the Better Software Conference & EXPO
September 19-22, 2005 * San Francisco, CA * Development Lifecycle Practices
Agile & Plan-Driven Development * Managing Projects & Teams * Testing & QA
Security * Process Improvement & Measurement * http://www.sqe.com/bsce5sf
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
