I am still experiencing this problem on a regular basis; not every job
does this, but it seems a good 40% do each night. I cleaned both of my
tape drives last night, but I still get the fatal errors. Here is another
example:
05-Dec 03:32 escabot-dir JobId 8219: BeforeJob: run command
"/usr/local/sbin/sun_snap_ctl.sh start mssql_data"
05-Dec 03:32 escabot-dir JobId 8219: BeforeJob: start: mssql_data
05-Dec 03:32 escabot-dir JobId 8219: BeforeJob: try # 1
05-Dec 03:32 escabot-dir JobId 8219: BeforeJob: sleeping...
05-Dec 03:33 escabot-dir JobId 8219: BeforeJob: rescanning fibre... 05-Dec
03:33 escabot-dir JobId 8219: BeforeJob: sleeping...
05-Dec 03:33 escabot-dir JobId 8219: BeforeJob: found the node: /dev/sdw
05-Dec 03:33 escabot-dir JobId 8219: BeforeJob: rereading the partition
table for
/dev/sdw...
05-Dec 03:33 escabot-dir JobId 8219: BeforeJob: sleeping...
05-Dec 03:33 escabot-dir JobId 8219: BeforeJob: mounting /dev/sdw1 @
/snapshots/mssql_data/1...
05-Dec 03:33 escabot-dir JobId 8219: Start Backup JobId 8219,
Job=sun_mssql_data.2007-12-05_02.00.39
05-Dec 03:33 escabot-dir JobId 8219: Using Device "T50-Drive-1"
05-Dec 03:33 escabot-sd JobId 8219: Error: Autochanger Volume "" not found
in slot 2.
Setting InChanger to zero in catalog.
05-Dec 03:33 escabot-fd JobId 8219: Fatal error: job.c:1811 Bad response
to Append
Data command. Wanted 3000 OK data
, got 3903 Error append data
05-Dec 03:33 escabot-sd JobId 8219: Fatal error: askdir.c:332 NULL Volume
name. This
shouldn't happen!!!
05-Dec 03:33 escabot-sd JobId 8219: Warning: Director wanted Volume
"000097LX".
Current Volume "" not acceptable because:
1998 Volume "" status is , not in Pool.
05-Dec 03:33 escabot-sd JobId 8219: Fatal error: Job 8219 canceled. 05-Dec
03:33 escabot-dir JobId 8219: Error: Bacula escabot-dir 2.2.6 (10Nov07):
05-Dec-2007 03:33:27
Build OS: i686-pc-linux-gnu gentoo
JobId: 8219
Job: sun_mssql_data.2007-12-05_02.00.39
Backup Level: Differential, since=2007-12-03 15:42:02
Client: "escabot-fd" 2.2.6 (10Nov07)
i686-pc-linux-gnu,gentoo,
FileSet: "sun_snap-mssql_data" 2007-07-26 09:36:24 Pool:
"Daily" (From Run pool override)
Storage: "SpectraLogicT50" (From Job resource)
Scheduled time: 05-Dec-2007 02:00:00
Start time: 05-Dec-2007 03:33:27
End time: 05-Dec-2007 03:33:27
Elapsed time: 0 secs
Priority: 22
FD Files Written: 0
SD Files Written: 0
FD Bytes Written: 0 (0 B)
SD Bytes Written: 0 (0 B)
Rate: 0.0 KB/s
Software Compression: None
VSS: no
Encryption: no
Volume name(s):
Volume Session Id: 87
Volume Session Time: 1196800690
Last Volume Bytes: 85,736,125,440 (85.73 GB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: Error
SD termination status: Error
Termination: *** Backup Error ***
Whats strange is a job or two later, it will use the same volume just
fine. I'm just not sure if why it gets NULL volume names -- is that coming
from the tape library, or maybe something is corrupt in the database?
Anyone else having/seen this problem?
Thanks,
Marc
> Hi,
>
> I am using Bacula 2.2.6 with a Spectra Logic T50 tape library (with 2
LTO3
> drives). I have about 20 jobs that are run nightly, allowing Bacula to
run
> multiple jobs at once (one on each drive).
>
> Here are my configuration files & log:
>
> http://esweb.mcc.edu/~marc.smith/bacula/
>
> This seems to happen somewhat randomly, usually happens to a few of my
jobs each night. Other nights it doesn't happen to any. I can't really
seem to reproduce the problem reliably, I happened to get lucky this time
> when I started 2 jobs. Here are the errors:
>
> 27-Nov 17:20 escabot-fd JobId 7784: Fatal error: job.c:1811 Bad response
to Append Data command. Wanted 3
> 000 OK data
> , got 3903 Error append data
>
> 27-Nov 17:20 escabot-sd JobId 7784: Fatal error: 3992 Bad autochanger
"load slot 10, drive 1": ERR=Child
> died from signal 15: Termination.
> Results=source Element Address 4105 is Empty
> Program killed by Bacula watchdog (timeout)
>
> 27-Nov 17:20 escabot-sd JobId 7783: 3301 Issuing autochanger "loaded?
drive 0" command.
> 27-Nov 17:20 escabot-dir JobId 7784: Error: Bacula escabot-dir 2.2.6
(10Nov07): 27-Nov-2007 17:20:07
> Build OS: i686-pc-linux-gnu gentoo
> JobId: 7784
> Job: sun_squid_data.2007-11-27_17.12.04
> Backup Level: Differential, since=2007-11-25 16:38:02
Client: "escabot-fd" 2.2.6 (10Nov07)
> i686-pc-linux-gnu,gentoo,
> FileSet: "sun_snap-squid_data" 2007-07-26 09:36:19
Pool:
> "Daily" (From Job resource)
> Storage: "SpectraLogicT50" (From Job resource)
> Scheduled time: 27-Nov-2007 17:12:20
> Start time: 27-Nov-2007 17:14:47
> End time: 27-Nov-2007 17:20:07
> Elapsed time: 5 mins 20 secs
> Priority: 22
> FD Files Written: 0
> SD Files Written: 0
> FD Bytes Written: 0 (0 B)
> SD Bytes Written: 0 (0 B)
> Rate: 0.0 KB/s
> Software Compression: None
> VSS: no
> Encryption: no
> Volume name(s):
> Volume Session Id: 2
> Volume Session Time: 1196201503
> Last Volume Bytes: 692,129,636,352 (692.1 GB)
> Non-fatal FD errors: 0
> SD Errors: 0
> FD termination status: Error
> SD termination status: Error
> Termination: *** Backup Error ***
>
> 27-Nov 17:20 escabot-sd JobId 7783: 3302 Autochanger "loaded? drive 0",
result is Slot 10.
> 27-Nov 17:20 escabot-sd JobId 7783: Error: Autochanger Volume "" not
found
> in slot 10.
> Setting InChanger to zero in catalog.
> 27-Nov 17:20 escabot-fd JobId 7783: Fatal error: job.c:1811 Bad response
to Append Data command. Wanted 3
> 000 OK data
> , got 3903 Error append data
>
> 27-Nov 17:20 escabot-sd JobId 7783: Fatal error: askdir.c:332 NULL
Volume
> name. This shouldn't happen!!!
> 27-Nov 17:20 escabot-sd JobId 7783: Warning: Director wanted Volume
"000034LX".
> Current Volume "" not acceptable because:
> 1998 Volume "" status is , not in Pool.
> 27-Nov 17:20 escabot-sd JobId 7783: Fatal error: Job 7783 canceled.
27-Nov
> 17:20 escabot-dir JobId 7783: Error: Bacula escabot-dir 2.2.6 (10Nov07):
27-Nov-2007 17:20:14
> Build OS: i686-pc-linux-gnu gentoo
> JobId: 7783
> Job: sun_home_fac_staff.2007-11-27_17.15.03 Backup
Level: Differential, since=2007-11-25 12:40:08 Client:
"escabot-fd" 2.2.6 (10Nov07)
> i686-pc-linux-gnu,gentoo,
> FileSet: "sun_snap-home_fac_staff" 2007-05-30 15:59:34
> Pool: "Daily" (From Job resource)
> Storage: "SpectraLogicT50" (From Job resource)
> Scheduled time: 27-Nov-2007 17:15:02
> Start time: 27-Nov-2007 17:12:36
> End time: 27-Nov-2007 17:20:14
> Elapsed time: 7 mins 38 secs
> Priority: 22
> FD Files Written: 0
> SD Files Written: 0
> FD Bytes Written: 0 (0 B)
> SD Bytes Written: 0 (0 B)
> Rate: 0.0 KB/s
> Software Compression: None
> VSS: no
> Encryption: no
> Volume name(s):
> Volume Session Id: 1
> Volume Session Time: 1196201503
> Last Volume Bytes: 692,129,636,352 (692.1 GB)
> Non-fatal FD errors: 0
> SD Errors: 0
> FD termination status: Error
> SD termination status: Error
> Termination: *** Backup Error ***
>
>
> Hopefully this is just something simple I am doing wrong.
>
> Thanks in advance for any help.
>
>
> --Marc
>
>
>
>
>
>
> -------------------------------------------------------------------------
SF.Net email is sponsored by: The Future of Linux Business White Paper
from Novell. From the desktop to the data center, Linux is going
mainstream. Let it simplify your IT future.
> http://altfarm.mediaplex.com/ad/ck/8857-50307-18918-4
> _______________________________________________
> Bacula-users mailing list
> Bacula-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
>
> !DSPAM:1,474d67f7206872353321418!
>
>
-------------------------------------------------------------------------
SF.Net email is sponsored by: The Future of Linux Business White Paper
from Novell. From the desktop to the data center, Linux is going
mainstream. Let it simplify your IT future.
http://altfarm.mediaplex.com/ad/ck/8857-50307-18918-4
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
