On Thursday 13 September 2007 19:31, Dan Langille wrote: > On 13 Sep 2007 at 18:17, Kern Sibbald wrote: > > On Thursday 13 September 2007 17:06, Dan Langille wrote: > > > On 13 Sep 2007 at 16:46, Kern Sibbald wrote: > > > > On Thursday 13 September 2007 15:15, Dan Langille wrote: > > > > > On 12 Sep 2007 at 22:01, Dan Langille wrote: > > > > > > I'm just documenting this test failure. It's is more of a > > > > > > freeze, than a failure, but I have seen this issue before. > > > > > > Waiting for an appendable volume. > > > > > > > > > > > > On the console, I see: > > > > > > > > > > > > === Starting 2drive-incremental-2disk at 20:40:06 === > > > > > > > > > > > > That's about an hour ago. The test should take about 6 minutes. > > > > > > > > > > > > I am going to control-c this, and run that given test about 200 > > > > > > times overnight, with debug on. > > > > > > > > > > This cycle of tests failed rather early. There are no core files. > > > > > > > > > > ===== 2drive-incremental-2disk OK 22:11:38 ===== > > > > > ===== 2drive-incremental-2disk OK 22:12:26 ===== > > > > > ===== 2drive-incremental-2disk OK 22:23:27 ===== > > > > > ===== 2drive-incremental-2disk OK 22:24:16 ===== > > > > > ===== 2drive-incremental-2disk OK 22:35:17 ===== > > > > > ===== 2drive-incremental-2disk OK 22:36:05 ===== > > > > > !!!!! 2drive-incremental-2disk failed!!! !!!!! > > > > > !!!!! Restored files differ !!!!! > > > > > ===== 2drive-incremental-2disk OK 22:57:59 ===== > > > > > ===== 2drive-incremental-2disk OK 23:11:04 ===== > > > > > ===== 2drive-incremental-2disk OK 23:27:24 ===== > > > > > ===== 2drive-incremental-2disk OK 23:43:52 ===== > > > > > ===== 2drive-incremental-2disk OK 23:56:28 ===== > > > > > > > > > > Of note: > > > > > > > > > > 12-Sep 22:22 localhost-fd: NightlySave.2007-09-12_22.12.48 Fatal > > > > > error: Authorization key rejected by Storage daemon. > > > > > Please see http://www.bacula.org/rel- > > > > > manual/faq.html#AuthorizationErrors for help. > > > > > 12-Sep 22:23 localhost-fd: NightlySave.2007-09-12_22.12.48 Fatal > > > > > error: Failed to authenticate Storage daemon. > > > > > 12-Sep 22:23 localhost-dir: NightlySave.2007-09-12_22.12.48 Fatal > > > > > error: Socket error on Storage command: ERR=Broken pipe > > > > > 12-Sep 22:23 localhost-dir: NightlySave.2007-09-12_22.12.48 Error: > > > > > Bacula localhost-dir 2.3.4 (12Sep07): 12-Sep-2007 22:23:00 > > > > > > > > > > If you look at the test.out results above, there is no > > > > > failure/error that corresponds to the above times. That is, I > > > > > think "2drive- incremental-2disk OK 22:23:27" is a false positive. > > > > > It should report a failure. > > > > > > > > > > This "Fatal error: Authorization key rejected by Storage daemon." > > > > > failure occurs 5 times during the above tests. > > > > > > > > Dan, > > > > > > > > This looks like some sort of bug to me. Perhaps it is a race > > > > condition or something that is not being properly cleaned up. > > > > > > > > I propose the following for running your tests: > > > > > > Just so I get this right: > > > > 1. Set debug level -d100 on the command line of the SD. > > > > > > from bin/bacula-ctl-sd > > > ${BACSDBIN}/bacula-sd $2 ${OPTIONS} -v -c ${BACSDCFG}/bacula-sd.conf - > > > d100 > > > > Yes that should be fine. > > > > > > 2. Add a "setdebug level=0 storage=DDS-4" at the beginning of the > > > > test. I have done this and committed it. > > > > > > --- 2drive-incremental-2disk (revision 5518) > > > +++ 2drive-incremental-2disk (working copy) > > > @@ -39,6 +39,7 @@ > > > @output /dev/null > > > messages > > > @$out tmp/log1.out > > > +setdebug level=0 storage=DDS-4 > > > label storage=DDS-4 volume=TestVolume001 slot=1 Pool=Default drive=0 > > > label storage=DDS-4 volume=TestVolume002 slot=2 Pool=Default drive=1 > > > status storage=DDS-4 > > > > Well after thinking about it, I set the director's level at 100 too so > > that we could see both sides of the communication, then reset it. My > > update is in the SVN. > > > > > > 3. Re-run the tests and repost it as you did. > > > > > > > > The above will give us more information about what is going on during > > > > the authentication process. It *may* help point us to a potential > > > > problem. > > > > > > I'll start them running now. > > We have results. First, the two emails that are generated:
The output from the debug will go to stdout, so does not appear in the emails. Sorry for the confusion. Regards, Kern > > 13-Sep 13:01 localhost-dir: No prior Full backup Job record found. > 13-Sep 13:01 localhost-dir: No prior or suitable Full backup found in > catalog. Doing FULL backup. > 13-Sep 13:01 localhost-dir: Start Backup JobId 4, > Job=NightlySave.2007-09-13_13.01.04 > 13-Sep 13:01 localhost-dir: Using Device "Drive-0" > 13-Sep 13:11 localhost-fd: NightlySave.2007-09-13_13.01.04 Fatal > error: Authorization key rejected by Storage daemon. > Please see http://www.bacula.org/rel- > manual/faq.html#AuthorizationErrors for help. > 13-Sep 13:11 localhost-fd: NightlySave.2007-09-13_13.01.04 Fatal > error: Failed to authenticate Storage daemon. > 13-Sep 13:11 localhost-dir: NightlySave.2007-09-13_13.01.04 Fatal > error: Socket error on Storage command: ERR=Broken pipe > 13-Sep 13:11 localhost-dir: NightlySave.2007-09-13_13.01.04 Error: > Bacula localhost-dir 2.3.4 (12Sep07): 13-Sep-2007 13:11:16 > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 4 > Job: NightlySave.2007-09-13_13.01.04 > Backup Level: Full (upgraded from Incremental) > Client: "2drive2disk" 2.3.4 (12Sep07) i386-unknown- > freebsd7.0,freebsd,7.0-CURRENT > FileSet: "Full Set" 2007-09-13 13:01:01 > Pool: "Default" (From Job resource) > Storage: "DDS-4" (From Job resource) > Scheduled time: 13-Sep-2007 13:01:03 > Start time: 13-Sep-2007 13:01:05 > End time: 13-Sep-2007 13:11:16 > Elapsed time: 10 mins 11 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): > Volume Session Id: 4 > Volume Session Time: 1189702852 > Last Volume Bytes: 1,737,274 (1.737 MB) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: > SD termination status: Waiting on FD > Termination: *** Backup Error *** > > > > > 13-Sep 13:01 localhost-dir: Start Backup JobId 5, > Job=NightlySave.2007-09-13_13.01.05 > 13-Sep 13:01 localhost-dir: Using Device "Drive-1" > 13-Sep 13:11 localhost-fd: NightlySave.2007-09-13_13.01.05 Fatal > error: Authorization key rejected by Storage daemon. > Please see http://www.bacula.org/rel- > manual/faq.html#AuthorizationErrors for help. > 13-Sep 13:11 localhost-fd: NightlySave.2007-09-13_13.01.05 Fatal > error: Failed to authenticate Storage daemon. > 13-Sep 13:11 localhost-dir: NightlySave.2007-09-13_13.01.05 Fatal > error: Socket error on Storage command: ERR=Broken pipe > 13-Sep 13:11 localhost-dir: NightlySave.2007-09-13_13.01.05 Error: > Bacula localhost-dir 2.3.4 (12Sep07): 13-Sep-2007 13:11:22 > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 5 > Job: NightlySave.2007-09-13_13.01.05 > Backup Level: Incremental, since=2007-09-13 13:01:02 > Client: "2drive2disk" 2.3.4 (12Sep07) i386-unknown- > freebsd7.0,freebsd,7.0-CURRENT > FileSet: "Full Set" 2007-09-13 13:01:01 > Pool: "Default" (From Job resource) > Storage: "DDS-4" (From Job resource) > Scheduled time: 13-Sep-2007 13:01:04 > Start time: 13-Sep-2007 13:01:06 > End time: 13-Sep-2007 13:11:22 > Elapsed time: 10 mins 16 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): > Volume Session Id: 5 > Volume Session Time: 1189702852 > Last Volume Bytes: 868,746 (868.7 KB) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: > SD termination status: Waiting on FD > Termination: *** Backup Error *** > > Full regression output is available if it will help: > > http://www.langille.org/tmp/2drive-incremental-2disk.output.2.txt > (286KB) > > Search for Fatal error ------------------------------------------------------------------------- This SF.net email is sponsored by: Microsoft Defy all challenges. Microsoft(R) Visual Studio 2005. http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/ _______________________________________________ Bacula-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-devel
