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: 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
