On 13 Sep 2007 at 20:25, Kern Sibbald wrote: > 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.
Perhaps that will be near the URL at the end of this post. ;) > > 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 > > -- Dan Langille - http://www.langille.org/ Available for hire: http://www.freebsddiary.org/dan_langille.php ------------------------------------------------------------------------- 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
