Hi,

23.10.2007 22:11,, Michael Short wrote::
> Hello,
> 
> In my bacula configuration, I have a single client configuration (and
> job) for every one of my ~30 clients. However, recently, one of the
> jobs has started to act differently. When the backup starts, it starts
> again, only to cause the job to fail.

I assume it's always the same job that behaves like this?

> 21-Oct 18:00 secnet-def: Start Backup JobId 4376, Job=sv27.2007-10-21_18.00.07
> 21-Oct 18:00 secnet-def: Start Backup JobId 4376, Job=sv27.2007-10-21_18.00.07
> 21-Oct 17:42 sv27: DIR and FD clocks differ by -1078 seconds, FD
> automatically adjusting.

It might be started twice because the DIR clock jumps.

> 21-Oct 18:00 secnet-def: Labeled new Volume "sv270095" on device
> "sv27" (/home/bacula/storage/d1).
> 21-Oct 18:00 secnet-def: Wrote label to prelabeled Volume "sv270095"
> on device "sv27" (/home/bacula/storage/d1)
> 21-Oct 18:00 secnet-def: Volume used once. Marking Volume "sv270095" as Used.
> 21-Oct 17:42 sv27: Generate VSS snapshots. Driver="VSS Win 2003", 
> Drive(s)="CD"
> 21-Oct 18:00 secnet-def: Start Backup JobId 4376, Job=sv27.2007-10-21_18.00.07
> 21-Oct 17:42 sv27: DIR and FD clocks differ by -1078 seconds, FD
> automatically adjusting.
> 21-Oct 18:00 secnet-def: Labeled new Volume "sv270095" on device
> "sv27" (/home/bacula/storage/d1).
> 21-Oct 18:00 secnet-def: Wrote label to prelabeled Volume "sv270095"
> on device "sv27" (/home/bacula/storage/d1)
> 21-Oct 18:00 secnet-def: Volume used once. Marking Volume "sv270095" as Used.
> 21-Oct 17:42 sv27: Generate VSS snapshots. Driver="VSS Win 2003", 
> Drive(s)="CD"
> 21-Oct 18:00 secnet-def: Start Backup JobId 4376, Job=sv27.2007-10-21_18.00.07
> 21-Oct 17:42 sv27: DIR and FD clocks differ by -1078 seconds, FD
> automatically adjusting.
> 21-Oct 18:00 secnet-def: Labeled new Volume "sv270095" on device
> "sv27" (/home/bacula/storage/d1).
> 21-Oct 18:00 secnet-def: Wrote label to prelabeled Volume "sv270095"
> on device "sv27" (/home/bacula/storage/d1)

Definitely something funny going on here...

> 
> .... this volume labeling sherade continues to happen about 10 more times ....
> 
>   JobId:                  4376
>   Job:                    sv27.2007-10-21_18.00.07
>   Backup Level:           Incremental, since=2007-10-08 18:00:21
>   Client:                 "sv27" 2.0.0 (04Jan07) Linux,Cross-compile,Win32
>   FileSet:                "sv27" 2007-07-10 09:43:58
>   Pool:                   "sv27" (From Job resource)
>   Storage:                "sv27" (From Job resource)
>   Scheduled time:         21-Oct-2007 18:00:06
>   Start time:             21-Oct-2007 18:00:21
>   End time:               22-Oct-2007 18:01:02
>   Elapsed time:           1 day 41 secs
>   Priority:               10
>   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):         sv270095
>   Volume Session Id:      51
>   Volume Session Time:    1192828139
>   Last Volume Bytes:      2,999,807,971 (2.999 GB)
>   Non-fatal FD errors:    0
>   SD Errors:              0
>   FD termination status:  Error
>   SD termination status:  Error
>   Termination:            *** Backup Error ***
> 
> However, I will then get a second error for the same job (but not the
> same JobId!).

So that would be for the second job started.

> 22-Oct 18:01 secnet-def: Start Backup JobId 4397, Job=sv27.2007-10-22_18.00.07
> 22-Oct 18:01 secnet-def: Start Backup JobId 4397, Job=sv27.2007-10-22_18.00.07
> 22-Oct 18:01 secnet-def: Created new Volume "sv270096" in catalog.
> 22-Oct 17:43 sv27: DIR and FD clocks differ by -1083 seconds, FD
> automatically adjusting.
> 22-Oct 18:01 secnet-def: sv27.2007-10-22_18.00.07 Fatal error:
> acquire.c:355 Wanted to append to Volume "sv270096", but device "sv27"
> (/home/bacula/storage/d1) is busy writing on "sv270095" .
> 22-Oct 17:43 sv27: sv27.2007-10-22_18.00.07 Fatal error:
> ../../filed/job.c:1751 Bad response to Append Data command. Wanted
> 3000 OK data
> , got 3903 Error append data
> 
> 22-Oct 18:01 secnet-def: sv27.2007-10-22_18.00.07 Error: Bacula 2.0.3
> (06Mar07): 22-Oct-2007 18:01:16
>   JobId:                  4397
>   Job:                    sv27.2007-10-22_18.00.07
>   Backup Level:           Incremental, since=2007-10-08 18:00:21
>   Client:                 "sv27" 2.0.0 (04Jan07) Linux,Cross-compile,Win32
>   FileSet:                "sv27" 2007-07-10 09:43:58
>   Pool:                   "sv27" (From Job resource)
>   Storage:                "sv27" (From Job resource)
>   Scheduled time:         22-Oct-2007 18:00:06
>   Start time:             22-Oct-2007 18:01:14
>   End time:               22-Oct-2007 18:01:16
>   Elapsed time:           2 secs
>   Priority:               10
>   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:                    yes
>   Encryption:             no
>   Volume name(s):
>   Volume Session Id:      78
>   Volume Session Time:    1192828139
>   Last Volume Bytes:      0 (0 B)
>   Non-fatal FD errors:    0
>   SD Errors:              0
>   FD termination status:  Error
>   SD termination status:  Error
>   Termination:            *** Backup Error ***
> 
> Whats the dilio? Could this be a bug?

Possible.

Have you checked what happens when you run this job manually, when no 
other jobs are active?

Before you report this as a bug it would be good to supply some more 
information - the versions of Bacula, for example :-)

What I'd do in your situation is first making sure the problem happens 
also when only this one job is active, i.e. disable all your other 
jobs, or schedule this problem job differently.

Then, run the DIR with debug tracing enabled and see if that tells you 
something.

All this is worth the effort only with a reasonably recent version of 
Bacula as I suppose Kern would not spend much time on 1.38 bugs anymore...

Arno


> Sincerely,
> -Michael
> 
> -------------------------------------------------------------------------
> This SF.net email is sponsored by: Splunk Inc.
> Still grepping through log files to find problems?  Stop.
> Now Search log events and configuration files using AJAX and a browser.
> Download your FREE copy of Splunk now >> http://get.splunk.com/
> _______________________________________________
> Bacula-users mailing list
> Bacula-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
> 

-- 
Arno Lehmann
IT-Service Lehmann
www.its-lehmann.de

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Reply via email to