Kern Sibbald schrieb:
> > > At them moment I would consider this as a bug, but I would like to
> > > here Kern's opinion on this before I open a bug report.
> >
> > ... to confirm that assumption and give Kern something to work on.
>
> >From this email, I would probably close the bug report right away. I don't
> have any idea what system it is, what version of Bacula, nor do I see any
> output generated by Bacula. "llist volume=xxx" is best not a raw copy of
> some stdin. Also, there is no job output showing what happened with the
> volume before, during and after its status was changed.
Sorry Kern, you seem to have missed my first mail in this thread.
(Message-ID: <[EMAIL PROTECTED]>, Date:
2007-04-10 07:29:05 GMT)
I'll cut & paste it again. If it's still missing important information, please
let me know.
######
Hi,
bacula-dir 2.0.3, bacula-sd 2.0.3, bacula-fd 2.0.2, debian etch amd64,
postgres 8.1.7
Bacula is running fine here for a while. But this weekend bacula
chose to use fresh tape from the scratch pool for job #2 of a diff backup
instead of appending the data to the tape it was writing to a few
minutes before by the first of the two jobs.
Here are the two jobs:
Job {
Name = "SMTCZB0003"
Type = Backup
Client = SMTCZB0003
FileSet = "SMTCZB0003"
Schedule = "Regular Backup"
Storage = NEC-T40A
Messages = "Regular Backup"
Pool = Default
SpoolData=yes
Write Bootstrap = "/opt/bacula/var/bacula/working/SMTCZB0003.bsr"
Priority = 5
RunBeforeJob = "/usr/bin/ssh [snip]"
RunAfterJob = "/usr/bin/ssh [snip]"
}
Job {
Name = "VU0EM003"
Type = Backup
Client = VU0EM003
FileSet = "VU0EM003 Full"
Schedule = "Regular Backup"
Storage = NEC-T40A
Messages = "Regular Backup"
Pool = Default
SpoolData=yes
Write Bootstrap = "/opt/bacula/var/bacula/working/VU0EM003.bsr"
Priority = 10
}
..and the schedule:
Schedule {
Name = "Regular Backup"
Run = Level=Full Pool=Full 1st sun at 00:05
Run = Level=Differential Pool=Differential FullPool=Full 2nd-5th sun at 00:05
Run = Level=Incremental Pool=Incremental DifferentialPool=Differential
FullPool=Full tue-sat at 00:05
}
Both jobs have the same start time, but different priorities.
llist volumes shows
volretention: 2,678,400 <--- (31 days)
voluseduration: 345,600 <--- (4 days)
for all tapes in the diff pool
This is what happend this weekend:
Job #1:
08-Apr 00:05 VU0EM005: BeforeJob: run command "/usr/bin/ssh [snip]"
08-Apr 00:07 VU0EM005: Start Backup JobId 121,
Job=SMTCZB0003.2007-04-08_00.05.00
08-Apr 00:08 VU0EM005: 3307 Issuing autochanger "unload slot 4, drive 0"
command.
08-Apr 00:09 VU0EM005: 3304 Issuing autochanger "load slot 5, drive 0" command.
08-Apr 00:10 VU0EM005: 3305 Autochanger "load slot 5, drive 0", status is OK.
08-Apr 00:10 VU0EM005: 3301 Issuing autochanger "loaded? drive 0" command.
08-Apr 00:10 VU0EM005: 3302 Autochanger "loaded? drive 0", result is Slot 5.
08-Apr 00:10 VU0EM005: Recycled volume "06D124L3" on device "LTO3" (/dev/nst0),
all previous data lost.
That's fine, I expected volume 06D124L3 to be overwritten at this time.
08-Apr 00:10 VU0EM005: Max configured use duration exceeded. Marking Volume
"06D124L3" as Used.
But I don't know what happend at this point. Why does bacula mark volume
06D124L3 as used right after the job started. The configured duration time
is 4 days, I checked this.
08-Apr 00:10 VU0EM005: Spooling data ...
SMTCZB0003-fd: Filesystem change prohibited. Will not descend into
/var/lib/nfs/rpc_pipefs
SMTCZB0003-fd: Filesystem change prohibited. Will not descend into /dev
SMTCZB0003-fd: Filesystem change prohibited. Will not descend into /sys
SMTCZB0003-fd: Filesystem change prohibited. Will not descend into /boot
08-Apr 00:12 VU0EM005: Job write elapsed time = 00:02:23, Transfer rate = 6.766
M bytes/second
08-Apr 00:12 VU0EM005: Committing spooled data to Volume "06D124L3". Despooling
968,636,754 bytes ...
08-Apr 00:12 VU0EM005: Despooling elapsed time = 00:00:07, Transfer rate =
138.3 M bytes/second
08-Apr 00:12 VU0EM005: Sending spooled attrs to the Director. Despooling
1,543,784 bytes ...
08-Apr 00:12 VU0EM005: AfterJob: run command "/usr/bin/ssh [snip]"
08-Apr 00:12 VU0EM005: Bacula 2.0.3 (06Mar07): 08-Apr-2007 00:12:47
JobId: 121
Job: SMTCZB0003.2007-04-08_00.05.00
Backup Level: Differential, since=2007-04-01 00:07:10
Client: "SMTCZB0003" i686-pc-linux-gnu,redhat,Enterprise
release
FileSet: "SMTCZB0003" 2007-02-20 22:25:00
Pool: "Differential" (From Run pool override)
Storage: "NEC-T40A" (From Job resource)
Scheduled time: 08-Apr-2007 00:05:00
Start time: 08-Apr-2007 00:07:08
End time: 08-Apr-2007 00:12:47
Elapsed time: 5 mins 39 secs
Priority: 5
FD Files Written: 4,807
SD Files Written: 4,807
FD Bytes Written: 966,711,641 (966.7 MB)
SD Bytes Written: 967,611,394 (967.6 MB)
Rate: 2851.7 KB/s
Software Compression: None
VSS: no
Encryption: no
Volume name(s): 06D124L3
Volume Session Id: 40
Volume Session Time: 1174319761
Last Volume Bytes: 968,583,168 (968.5 MB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: OK
SD termination status: OK
Termination: Backup OK
08-Apr 00:12 VU0EM005: Begin pruning Jobs.
08-Apr 00:12 VU0EM005: No Jobs found to prune.
08-Apr 00:12 VU0EM005: Begin pruning Files.
08-Apr 00:12 VU0EM005: Pruned Files from 1 Jobs for client SMTCZB0003 from
catalog.
08-Apr 00:12 VU0EM005: End auto prune.
Job #2:
08-Apr 00:12 VU0EM005: Start Backup JobId 122, Job=VU0EM003.2007-04-08_00.05.01
08-Apr 00:12 VU0EM005: Using Volume "06D137L3" from 'Scratch' pool.
Ok, here bacula decided to use a volumes from the scratch pool, because
06D124L3 was marked as used a few minutes ago.
08-Apr 00:12 VU0EM005: 3307 Issuing autochanger "unload slot 5, drive 0"
command.
08-Apr 00:13 VU0EM005: 3304 Issuing autochanger "load slot 18, drive 0" command.
08-Apr 00:14 VU0EM005: 3305 Autochanger "load slot 18, drive 0", status is OK.
08-Apr 00:14 VU0EM005: 3301 Issuing autochanger "loaded? drive 0" command.
08-Apr 00:14 VU0EM005: 3302 Autochanger "loaded? drive 0", result is Slot 18.
08-Apr 00:14 VU0EM005: Wrote label to prelabeled Volume "06D137L3" on device
"LTO3" (/dev/nst0)
08-Apr 00:14 VU0EM005: Spooling data ...
VU0EM003: /home is a different filesystem. Will not descend from / into
/home
VU0EM003: /public is a different filesystem. Will not descend from / into
/public
VU0EM003: /lib/init/rw is a different filesystem. Will not descend from /
into /lib/init/rw
VU0EM003: /server is a different filesystem. Will not descend from / into
/server
08-Apr 00:16 VU0EM005: Job write elapsed time = 00:02:29, Transfer rate = 22.33
M bytes/second
08-Apr 00:16 VU0EM005: Committing spooled data to Volume "06D137L3". Despooling
3,331,622,332 bytes ...
08-Apr 00:17 VU0EM005: Despooling elapsed time = 00:00:47, Transfer rate =
70.88 M bytes/second
08-Apr 00:17 VU0EM005: Sending spooled attrs to the Director. Despooling
3,858,055 bytes ...
08-Apr 00:17 VU0EM005: Bacula 2.0.3 (06Mar07): 08-Apr-2007 00:17:46
JobId: 122
Job: VU0EM003.2007-04-08_00.05.01
Backup Level: Differential, since=2007-04-01 02:09:55
Client: "VU0EM003" 2.0.2 (28Jan07)
x86_64-unknown-linux-gnu,debian,4.0
FileSet: "VU0EM003 Full" 2007-02-25 16:22:49
Pool: "Differential" (From Run pool override)
Storage: "NEC-T40A" (From Job resource)
Scheduled time: 08-Apr-2007 00:05:00
Start time: 08-Apr-2007 00:12:51
End time: 08-Apr-2007 00:17:46
Elapsed time: 4 mins 55 secs
Priority: 10
FD Files Written: 12,681
SD Files Written: 12,681
FD Bytes Written: 3,325,991,618 (3.325 GB)
SD Bytes Written: 3,327,999,098 (3.327 GB)
Rate: 11274.5 KB/s
Software Compression: None
VSS: no
Encryption: no
Volume name(s): 06D137L3
Volume Session Id: 41
Volume Session Time: 1174319761
Last Volume Bytes: 3,331,077,120 (3.331 GB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: OK
SD termination status: OK
Termination: Backup OK
08-Apr 00:17 VU0EM005: Begin pruning Jobs.
08-Apr 00:17 VU0EM005: No Jobs found to prune.
08-Apr 00:17 VU0EM005: Begin pruning Files.
08-Apr 00:17 VU0EM005: Pruned Files from 1 Jobs for client VU0EM003 from
catalog.
08-Apr 00:17 VU0EM005: End auto prune.
Here's the shortened 'list volumes' output from today:
+-------+----------+---------+--------------+------------+-------+-------------------+
|mediaid|volumename|volstatus|volbytes |volretention|recycle|lastwritten
|
+-------+----------+---------+--------------+------------+-------+-------------------+
| 5 |06D124L3 |Used | 968,583,168| 2,678,400 | 1|2007-04-08
00:12:44|
| 6 |06D125L3 |Used |17,191,802,880| 2,678,400 | 1|2007-03-11
00:33:24|
| 7 |06D126L3 |Used | 6,299,725,824| 2,678,400 | 1|2007-03-19
21:07:48|
| 8 |06D127L3 |Used | 9,633,254,400| 2,678,400 | 1|2007-03-25
00:22:52|
| 19 |06D137L3 |Append | 3,497,001,984| 2,678,400 | 1|2007-04-08
00:18:03|
+-------+----------+---------+--------------+------------+-------+-------------------+
The main question is, why did bacula mark volumes 06D124L3 as used right after
the first job started when the voluseduration is set to 4 days?
-------------------------------------------------------------------------
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
