A couple days ago somebody made a comment that using pool overrides in a schedule was deprecated.  I’ve been using them for years, but I’ve been seeing a strange problem recently that I’m thinking might be related.

 

I’m running 5.0.2 on Debian, separate Dir/Mysql and SD systems, using files on an array.  I’m backing up several TB a week, but over a slow 25Mbps link, so some of my full jobs run for a very long time.  Concurrency is key.  I normally run 4 jobs at a time on my SD, and I spool (yes, probably unnecessary, but because the data is coming in so slowly, I feel better about writing it to volumes in big chunks.)

 

Right now I have one job actively running, with 4 more waiting on the SD.  As I mentioned before, usually 4 are running concurrently, but I frequently see less than 4 but have never really dug into it.  In the output below, note that the SD is running 4 (actually 5!) jobs, but only one is actually writing to the spool.  Two things jump out at me here: First, of the 5 running jobs, two are correctly noted as being for LF-Full, and 3 for LF-Inc (pool for Full backups and pool for Incremental backups respectively).  However, all 5 show the same volume (LF-F-0239, which is only in the LF-Full pool, and is currently being written to by the correctly-running job).  Second, in the Device Status section at the bottom, the pool of LF-F-0239 is listed as “*unknown*”; similarly, under “Jobs waiting to reserve a drive”, each job wants the correct pool, but the current pool is listed as “”.

 

Hopefully this is enough information to make sense of.  I tried to cut out everything I thought was unnecessary.  Thanks

 

Some console output follows:

 

*stat dir

bacula-dir Version: 5.0.2 (28 April 2010) i686-pc-linux-gnu debian 5.0.4

Daemon started 28-Dec-10 14:21, 444 Jobs run since started.

Heap: heap=1,093,632 smbytes=688,548 max_bytes=1,225,799 bufs=3,052 max_bufs=5,841

 

Scheduled Jobs:

Level          Type     Pri  Scheduled          Name               Volume

===================================================================================

Incremental    Backup    10  18-Jan-11 20:15    fs4-fd-full        LF-I-0237

Incremental    Backup    10  18-Jan-11 20:15    openfiler1-pvr-1   LF-I-0237

Incremental    Backup    10  18-Jan-11 20:15    file-server2-fd-full LF-I-0237

Incremental    Backup    10  18-Jan-11 20:15    phx-dc2-fd-full    LF-I-0237

--other jobs omitted—

 

JobId Level   Name                       Status

======================================================================

18038 Full    oraclerac1-fd-full.2011-01-17_08.25.16_44 is running

18040 Full    mailserverx-fd-full.2011-01-17_08.25.46_46 is waiting on Storage LocalFiles

18041 Increme  fs4-fd-full.2011-01-17_20.15.00_48 is waiting on Storage LocalFiles

18042 Increme  cacti-fd-full.2011-01-17_20.15.00_49 is waiting on Storage LocalFiles

18043 Increme  acu-leap-test-fd-full.2011-01-17_20.15.00_50 is waiting on Storage LocalFiles

18044 Full    dns3-fd-full.2011-01-17_20.15.00_51 is waiting execution

18045 Increme  dns4-fd-full.2011-01-17_20.15.00_52 is waiting on max Storage jobs

18046 Increme  pcontroller1-fd-full.2011-01-17_20.15.00_53 is waiting on max Storage jobs

--other jobs omitted—

 

 

*stat storage=LocalFiles

Connecting to Storage daemon LocalFiles at baculasd.hq.ilinc.com:9103

 

baculasd-sd Version: 5.0.2 (28 April 2010) x86_64-unknown-linux-gnu debian 5.0.7

Daemon started 11-Jan-11 09:19, 125 Jobs run since started.

Heap: heap=1,458,176 smbytes=907,450 max_bytes=1,295,252 bufs=236 max_bufs=303

Sizes: boffset_t=8 size_t=8 int32_t=4 int64_t=8

 

Running Jobs:

Writing: Full Backup job oraclerac1-fd-full JobId=18038 Volume="LF-F-0239"

    pool="LF-Full" device="LocalFiles" (/data/bacula)

    spooling=1 despooling=0 despool_wait=0

    Files=99,312 Bytes=36,245,783,238 Bytes/sec=533,984

    FDReadSeqNo=2,236,739 in_msg=1764881 out_msg=5 fd=5

Writing: Full Backup job mailserverx-fd-full JobId=18040 Volume="LF-F-0239"

    pool="LF-Full" device="LocalFiles" (/data/bacula)

    spooling=0 despooling=0 despool_wait=0

    Files=0 Bytes=0 Bytes/sec=0

    FDSocket closed

Writing: Incremental Backup job fs4-fd-full JobId=18041 Volume="LF-F-0239"

    pool="LF-Inc" device="LocalFiles" (/data/bacula)

    spooling=0 despooling=0 despool_wait=0

    Files=0 Bytes=0 Bytes/sec=0

    FDSocket closed

Writing: Incremental Backup job cacti-fd-full JobId=18042 Volume="LF-F-0239"

    pool="LF-Inc" device="LocalFiles" (/data/bacula)

    spooling=0 despooling=0 despool_wait=0

    Files=0 Bytes=0 Bytes/sec=0

    FDSocket closed

Writing: Incremental Backup job acu-leap-test-fd-full JobId=18043 Volume="LF-F-0239"

    pool="LF-Inc" device="LocalFiles" (/data/bacula)

    spooling=0 despooling=0 despool_wait=0

    Files=0 Bytes=0 Bytes/sec=0

    FDSocket closed

====

 

Jobs waiting to reserve a drive:

   3608 JobId=18040 wants Pool="LF-Full" but have Pool="" nreserve=0 on drive "LocalFiles" (/data/bacula).

   3608 JobId=18041 wants Pool="LF-Inc" but have Pool="" nreserve=0 on drive "LocalFiles" (/data/bacula).

   3608 JobId=18042 wants Pool="LF-Inc" but have Pool="" nreserve=0 on drive "LocalFiles" (/data/bacula).

   3608 JobId=18043 wants Pool="LF-Inc" but have Pool="" nreserve=0 on drive "LocalFiles" (/data/bacula).

====

 

--Terminated jobs omitted—

Device status:

Device "LocalFiles" (/data/bacula) is mounted with:

    Volume:      LF-F-0239

    Pool:        *unknown*

    Media type:  File

    Total Bytes=68,815,120,050 Blocks=1,066,705 Bytes/block=64,511

    Positioned at File=16 Block=95,643,313

====

 

Used Volume status:

LF-F-0239 on device "LocalFiles" (/data/bacula)

    Reader=0 writers=1 devres=0 volinuse=1

====

 

Data spooling: 1 active jobs, 1,288,415,222 bytes; 108 total jobs, 15,955,752,092 max bytes/job.

Attr spooling: 1 active jobs, 0 bytes; 108 total jobs, 939,900,748 max bytes.

====