Could you be sure you are updated to the latest SVN and let me know if the crash is still happening. The date printed by Bacula is still listed as 30 September 2007 so you may well be on the latest code.
Also, please make sure the executable and the source code correspond. The traceback is complaining about that. I've just made a new commit that adds a bit more code and updates the signon date. Kern On Friday 05 October 2007 18:21, Dan Langille wrote: > This is still on FreeBSD 7.x so I would not put much effort into > tracking this down unless there is something very obvious in the > DEBUG output. > > The following DEBUG output is from an incremental test. It can be > repeated, although not every time. > > Traceback first, then the DEBUG output: > > [EMAIL PROTECTED]:~/src/BaculaRegressionTesting] $ gdb bin/bacula-sd bacula- > sd.core > GNU gdb 6.1.1 [FreeBSD] > Copyright 2004 Free Software Foundation, Inc. > GDB is free software, covered by the GNU General Public License, and > you are > welcome to change it and/or distribute copies of it under certain > conditions. > Type "show copying" to see the conditions. > There is absolutely no warranty for GDB. Type "show warranty" for > details. > This GDB was configured as "i386-marcel-freebsd"... > Core was generated by `bacula-sd'. > Program terminated with signal 11, Segmentation fault. > Reading symbols from /lib/libz.so.4...done. > Loaded symbols for /lib/libz.so.4 > Reading symbols from /lib/libthr.so.3...done. > Loaded symbols for /lib/libthr.so.3 > Reading symbols from /usr/local/lib/libintl.so.8...done. > Loaded symbols for /usr/local/lib/libintl.so.8 > Reading symbols from /usr/local/lib/libiconv.so.3...done. > Loaded symbols for /usr/local/lib/libiconv.so.3 > Reading symbols from /usr/lib/libssl.so.5...done. > Loaded symbols for /usr/lib/libssl.so.5 > Reading symbols from /lib/libcrypto.so.5...done. > Loaded symbols for /lib/libcrypto.so.5 > Reading symbols from /usr/lib/libstdc++.so.6...done. > Loaded symbols for /usr/lib/libstdc++.so.6 > Reading symbols from /lib/libm.so.5...done. > Loaded symbols for /lib/libm.so.5 > Reading symbols from /lib/libgcc_s.so.1...done. > Loaded symbols for /lib/libgcc_s.so.1 > Reading symbols from /lib/libc.so.7...done. > Loaded symbols for /lib/libc.so.7 > Reading symbols from /libexec/ld-elf.so.1...done. > Loaded symbols for /libexec/ld-elf.so.1 > #0 0x0807c338 in bvsnprintf (buffer=0xbf8fc6fe "free vol_list > Volume=TestVolume001 dev=n/src/BaculaRegressionTesting/tmp\n", > maxlen=4970, format=0x809d6ae "\n", args=0xbf8fda98 > "¨Ú\217¿\224á\006\b") at bsnprintf.c:413 > > warning: Source file is more recent than executable. > > 413 strln = strlen(value); > [New Thread 0x28601300 (LWP 100270)] > [New Thread 0x28601100 (LWP 100445)] > (gdb) traceback > Undefined command: "traceback". Try "help". > (gdb) backtrace > #0 0x0807c338 in bvsnprintf (buffer=0xbf8fc6fe "free vol_list > Volume=TestVolume001 dev=n/src/BaculaRegressionTesting/tmp\n", > maxlen=4970, format=0x809d6ae "\n", args=0xbf8fda98 > "¨Ú\217¿\224á\006\b") at bsnprintf.c:413 > #1 0x08084a46 in d_msg (file=0x809cfa3 "reserve.c", line=513, > level=0, fmt=0x809d690 "free vol_list Volume=%s dev=%s\n") > at message.c:864 > #2 0x0806e204 in free_volume_list () at reserve.c:515 > #3 0x0804cf94 in terminate_stored (sig=15) at stored.c:608 > #4 0x0808c245 in signal_handler (sig=15) at signal.c:180 > #5 0xbfbfffb4 in ?? () > #6 0x0000000f in ?? () > #7 0x00000000 in ?? () > #8 0xbf8fdbc0 in ?? () > #9 0x00000000 in ?? () > #10 0x0808bef0 in get_signal_name () at signal.c:72 > #11 0x280f81de in pthread_cond_init () from /lib/libthr.so.3 > #12 0x0808f74b in watchdog_thread (arg=0x0) at watchdog.c:307 > #13 0x280f1a7f in pthread_getprio () from /lib/libthr.so.3 > #14 0x00000000 in ?? () > Current language: auto; currently c++ > (gdb) > > > > [EMAIL PROTECTED]:~/src/BaculaRegressionTesting] $ tests/incremental-2media > Orphaned buffer: localhost-sd 8 bytes buf=28608328 allocated at > workq.c:16 7 > > > === Starting incremental-2media at 15:40:06 === > > Starting the Bacula Storage daemon > Starting the Bacula File daemon > Starting the Bacula Director daemon > Connecting to Director localhost:8101 > 1000 OK: localhost-dir Version: 2.3.6 (30 September 2007) > Enter a period to cancel a command. > @tee /dev/null > messages > 05-Oct 15:37 localhost-dir: threepooldisk.2007-10-05_15.31.07 Fatal > error: > Netwo rk > error with > FD during Backup: ERR=Broken pipe > 05-Oct 15:37 localhost-dir: threepooldisk.2007-10-05_15.31.06 Fatal > error: > Netwo rk > error with > FD during Backup: ERR=Broken pipe > 05-Oct 15:37 localhost-sd: Job threepooldisk.2007-10-05_15.31.07 > marked to > be ca > nceled. > 05-Oct 15:37 localhost-sd: Job threepooldisk.2007-10-05_15.31.06 > marked to > be ca > nceled. > 05-Oct 15:37 localhost-sd: Job threepooldisk.2007-10-05_15.31.06 > canceled > while > waiting for > mount on Storage Device ""Drive-1" (/usr/home/dan/src/BaculaRegressi > onTesting/tmp/disk-changer/drive1)". > 05-Oct 15:37 localhost-sd: threepooldisk.2007-10-05_15.31.07 Fatal > error: > Job 5 > canceled. > 05-Oct 15:37 localhost-dir: threepooldisk.2007-10-05_15.31.07 Fatal > error: > No Jo b > status > returned from FD. > 05-Oct 15:37 localhost-dir: threepooldisk.2007-10-05_15.31.06 Fatal > error: > No Jo b > status > returned from FD. > 05-Oct 15:37 localhost-dir: threepooldisk.2007-10-05_15.31.07 Error: > Bacula > loca lhost- > dir > 2.3.6 (30Sep07): 05-Oct-2007 15:37:20 > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 5 > Job: threepooldisk.2007-10-05_15.31.07 > Backup Level: Full > Client: "localhost-fd" 2.3.6 (30Sep07) > i386-unknown-freebsd7.0 > ,freebsd,7.0-CURRENT > FileSet: "Full Set" 2007-10-05 15:31:37 > Pool: "Default" (From Job resource) > Storage: "DDS-4" (From Job resource) > Scheduled time: 05-Oct-2007 15:31:37 > Start time: 05-Oct-2007 15:32:28 > End time: 05-Oct-2007 15:37:20 > Elapsed time: 4 mins 52 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: 1191598288 > Last Volume Bytes: 218 (218 B) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: Error > SD termination status: Canceled > Termination: *** Backup Error *** > > 05-Oct 15:37 localhost-dir: threepooldisk.2007-10-05_15.31.06 Error: > Bacula > loca lhost- > dir > 2.3.6 (30Sep07): 05-Oct-2007 15:37:20 > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 4 > Job: threepooldisk.2007-10-05_15.31.06 > Backup Level: Full > Client: "localhost-fd" 2.3.6 (30Sep07) > i386-unknown-freebsd7.0 > ,freebsd,7.0-CURRENT > FileSet: "Full Set" 2007-10-05 15:31:37 > Pool: "Default" (From Job resource) > Storage: "DDS-4" (From Job resource) > Scheduled time: 05-Oct-2007 15:31:37 > Start time: 05-Oct-2007 15:31:41 > End time: 05-Oct-2007 15:37:20 > Elapsed time: 5 mins 39 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: 1191598288 > Last Volume Bytes: 0 (0 B) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: Error > SD termination status: Canceled > Termination: *** Backup Error *** > > 05-Oct 15:37 localhost-dir: Start Restore Job > RestoreFiles.2007-10-05_15.37.09 > 05-Oct 15:37 localhost-dir: Using Device "Drive-0" > 05-Oct 15:37 localhost-dir: RestoreFiles.2007-10-05_15.37.09 Warning: > bsock.c:12 3 > Could > not connect to Client: localhost-fd on localhost:8102. ERR=Connection > re > fused > Retrying ... > @tee /usr/home/dan/src/BaculaRegressionTesting/tmp/log1.out > label storage=DDS-4 volume=TestVolume001 slot=1 Pool=Default drive=0 > Automatically selected Catalog: MyCatalog > Using Catalog "MyCatalog" > Connecting to Storage daemon DDS-4 at localhost:8103 ... > Sending label command for Volume "TestVolume001" Slot 1 ... > 3301 Issuing autochanger "loaded? drive 0" command. > 3302 Autochanger "loaded? drive 0", result: nothing loaded. > 3304 Issuing autochanger "load slot 1, drive 0" command. > 3305 Autochanger "load slot 1, drive 0", status is OK. > 3301 Issuing autochanger "loaded? drive 0" command. > 3302 Autochanger "loaded? drive 0", result is Slot 1. > 3301 Issuing autochanger "loaded? drive 0" command. > 3302 Autochanger "loaded? drive 0", result is Slot 1. > 3000 OK label. VolBytes=218 DVD=0 Volume="TestVolume001" > Device="Drive-0" > (/usr/ > home/dan/src/BaculaRegressionTesting/tmp/disk-changer/drive0) > Catalog record for Volume "TestVolume001", Slot 1 successfully > created. > Requesting to mount DDS-4 ... > 3002 Device "Drive-0" > (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-change > r/drive0) is mounted. > label storage=File volume=TestVolume002 Pool=Default > Connecting to Storage daemon File at localhost:8103 ... > Sending label command for Volume "TestVolume002" Slot 0 ... > 3000 OK label. VolBytes=222 DVD=0 Volume="TestVolume002" > Device="FileStorage" (/ > usr/home/dan/src/BaculaRegressionTesting/tmp) > Catalog record for Volume "TestVolume002", Slot 0 successfully > created. > Requesting to mount FileStorage ... > 3906 File device "FileStorage" > (/usr/home/dan/src/BaculaRegressionTesting/tmp) i > s always mounted. > run job=Inc2media yes > Job queued. JobId=1 > You have messages. > wait > messages > 05-Oct 15:40 localhost-dir: No prior Full backup Job record found. > 05-Oct 15:40 localhost-dir: No prior or suitable Full backup found in > catalog. D > oing > FULL backup. > 05-Oct 15:40 localhost-dir: Start Backup JobId 1, > Job=Inc2media.2007-10-05_15.40 > .03 > 05-Oct 15:40 localhost-dir: Using Device "Drive-0" > 05-Oct 15:40 localhost-sd: 3301 Issuing autochanger "loaded? drive 0" > command. > 05-Oct 15:40 localhost-sd: 3302 Autochanger "loaded? drive 0", result > is > Slot 1. > 05-Oct 15:40 localhost-sd: 3301 Issuing autochanger "loaded? drive 0" > command. > 05-Oct 15:40 localhost-sd: 3302 Autochanger "loaded? drive 0", result > is > Slot 1. > 05-Oct 15:40 localhost-sd: Wrote label to prelabeled Volume > "TestVolume001" > on d evice > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/driv > e0) > 05-Oct 15:40 localhost-sd: Spooling data ... > 05-Oct 15:40 localhost-sd: Job write elapsed time = 00:00:17, > Transfer rate > = 4. 077 M > bytes/second > 05-Oct 15:40 localhost-sd: Committing spooled data to Volume > "TestVolume001". De > spooling 69,554,708 bytes ... > 05-Oct 15:40 localhost-sd: Despooling elapsed time = 00:00:02, > Transfer rate > = 3 4.77 M > bytes/second > 05-Oct 15:40 localhost-sd: Sending spooled attrs to the Director. > Despooling > 1,7 20,654 > bytes > ... > 05-Oct 15:40 localhost-dir: Bacula localhost-dir 2.3.6 (30Sep07): > 05-Oct-2007 15 > > :40:39 > > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 1 > Job: Inc2media.2007-10-05_15.40.03 > Backup Level: Full (upgraded from Incremental) > Client: "localhost-fd" 2.3.6 (30Sep07) > i386-unknown-freebsd7.0 > ,freebsd,7.0-CURRENT > FileSet: "Full Set" 2007-10-05 15:40:15 > Pool: "Default" (From Job resource) > Storage: "DDS-4" (From Job resource) > Scheduled time: 05-Oct-2007 15:40:15 > Start time: 05-Oct-2007 15:40:17 > End time: 05-Oct-2007 15:40:39 > Elapsed time: 22 secs > Priority: 10 > FD Files Written: 5,484 > SD Files Written: 5,484 > FD Bytes Written: 68,392,516 (68.39 MB) > SD Bytes Written: 69,324,290 (69.32 MB) > Rate: 3108.8 KB/s > Software Compression: None > VSS: no > Encryption: no > Volume name(s): TestVolume001 > Volume Session Id: 1 > Volume Session Time: 1191598806 > Last Volume Bytes: 69,541,990 (69.54 MB) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: OK > SD termination status: OK > Termination: Backup OK > > 05-Oct 15:40 localhost-dir: Begin pruning Jobs. > 05-Oct 15:40 localhost-dir: No Jobs found to prune. > 05-Oct 15:40 localhost-dir: Begin pruning Files. > 05-Oct 15:40 localhost-dir: No Files found to prune. > 05-Oct 15:40 localhost-dir: End auto prune. > > quit > Backup 1 done > Connecting to Director localhost:8101 > 1000 OK: localhost-dir Version: 2.3.6 (30 September 2007) > Enter a period to cancel a command. > @tee /dev/null > messages > You have no messages. > @tee /usr/home/dan/src/BaculaRegressionTesting/tmp/log1.out > @# Force Incremental on the second Volume > update volume=TestVolume001 VolStatus=Used > Automatically selected Catalog: MyCatalog > Using Catalog "MyCatalog" > New Volume status is: Used > setdebug level=51 storage=File > Connecting to Storage daemon File at localhost:8103 > 3000 OK setdebug=51 > run level=Incremental job=Inc2media storage=File yes > Job queued. JobId=2 > wait > localhost-sd: cram-md5.c:73-0 send: auth cram-md5 > <[EMAIL PROTECTED] > t-sd> ssl=0 > localhost-sd: reserve.c:583-2 <dird: use storage=File > media_type=FileMedia > pool_ > name=Default > pool_type=Backup append=1 copy=0 stripe=0 > localhost-sd: reserve.c:612-2 <dird device: use device=FileStorage > localhost-sd: reserve.c:628-2 Storage=File media_type=FileMedia > pool=Default > poo > l_type=Backup > append=1 > localhost-sd: reserve.c:630-2 Device=FileStorage > localhost-sd: reserve.c:708-2 PrefMnt=1 exact=1 suitable=0 chgronly=0 > any=0 > localhost-sd: reserve.c:815-2 PrefMnt=1 exact=1 suitable=0 chgronly=0 > localhost-sd: reserve.c:827-2 lock volumes > localhost-sd: reserve.c:838-2 duplicate vol list > localhost-sd: reserve.c:854-2 unlock volumes > localhost-sd: reserve.c:858-2 look for vol in vol list > localhost-sd: reserve.c:870-2 vol=TestVolume002 OK for this job > localhost-sd: reserve.c:893-2 try vol=TestVolume002 on > device=FileStorage > localhost-sd: reserve.c:1036-2 chk MediaType device=FileMedia > request=FileMedia > localhost-sd: reserve.c:1059-2 try reserve FileStorage > localhost-sd: reserve.c:1072-2 have_vol=1 vol=TestVolume002 > localhost-sd: reserve.c:1246-2 reserve_append device is "FileStorage" > (/usr/home > /dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:1322-2 PrefMnt=1 exact=1 suitable=1 > chgronly=0 any=0 > localhost-sd: reserve.c:1372-2 PrefMnt=1 exact=1 suitable=1 > chgronly=0 any=0 > localhost-sd: reserve.c:1375-2 have_vol=1 have= resvol=TestVolume002 > want=TestVo > lume002 > localhost-sd: reserve.c:405-2 find_vol=TestVolume002 found=1 > localhost-sd: reserve.c:179-2 List from find_volume: TestVolume001 at > 288090b8 o n > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/d > rive0) > localhost-sd: reserve.c:179-2 List from find_volume: TestVolume002 at > 289090b8 o n > device > "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:535-2 Vol=TestVolume002 on same dev. > localhost-sd: reserve.c:1423-2 OK Dev avail reserved "FileStorage" > (/usr/home/da > n/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:1256-2 Inc reserve=1 dev="FileStorage" > (/usr/home/dan/sr > c/BaculaRegressionTesting/tmp) 2870c818 > localhost-sd: reserve.c:1081-2 Reserved=1 dev_name=FileStorage > mediatype=FileMed > ia pool=Default ok=1 > localhost-sd: reserve.c:1143-2 >dird: 3000 OK use device > device=FileStorage > localhost-sd: reserve.c:896-2 Suitable device found=FileStorage > localhost-sd: reserve.c:916-2 lock volumes > localhost-sd: reserve.c:513-2 free vol_list Volume=TestVolume001 > dev="Drive-0" ( > /usr/home/dan/src/BaculaRegressionTesting/tmp/disk-changer/drive0) > localhost-sd: reserve.c:513-2 free vol_list Volume=TestVolume002 > /dev="FileStorag > e" > (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:922-2 deleted temp vol list > localhost-sd: reserve.c:923-2 lock volumes > localhost-sd: reserve.c:927-2 got vol TestVolume002 from in-use vols > list > localhost-sd: job.c:177-2 Inc2media.2007-10-05_15.40.05 waiting 1800 > sec for > FD to > contact SD > key=DNFE-BNLJ-GFFB-DCMH-CHNG-MPPO-GPPI-KDOA > localhost-sd: cram-md5.c:73-0 send: auth cram-md5 > <[EMAIL PROTECTED] > st-sd> ssl=0 > localhost-sd: reserve.c:405-2 find_vol=TestVolume002 found=1 > localhost-sd: reserve.c:179-2 List from find_volume: TestVolume001 at > 288090b8 o n > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/d > rive0) > localhost-sd: reserve.c:179-2 List from find_volume: TestVolume002 at > 289090b8 o n > device > "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:535-2 Vol=TestVolume002 on same dev. > localhost-sd: reserve.c:311-2 reserve_volume TestVolume002 > localhost-sd: reserve.c:179-2 List from begin reserve_volume: > TestVolume001 > at 2 88090b8 > on > device "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/drive0) > localhost-sd: reserve.c:179-2 List from begin reserve_volume: > TestVolume002 > at 2 89090b8 > on > device "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:330-2 OK, vol=TestVolume002 on device. > localhost-sd: reserve.c:179-2 List from end new volume: TestVolume001 > at > 288090b 8 on > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-change > r/drive0) > localhost-sd: reserve.c:179-2 List from end new volume: TestVolume002 > at > 289090b 8 on > device > "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:311-2 reserve_volume TestVolume002 > localhost-sd: reserve.c:179-2 List from begin reserve_volume: > TestVolume001 > at 2 88090b8 > on > device "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/drive0) > localhost-sd: reserve.c:179-2 List from begin reserve_volume: > TestVolume002 > at 2 89090b8 > on > device "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:330-2 OK, vol=TestVolume002 on device. > localhost-sd: reserve.c:179-2 List from end new volume: TestVolume001 > at > 288090b 8 on > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-change > r/drive0) > localhost-sd: reserve.c:179-2 List from end new volume: TestVolume002 > at > 289090b 8 on > device > "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > > Volume Label: > Id : Bacula 1.0 immortal > VerNo : 11 > VolName : TestVolume002 > PrevVolName : > VolFile : 0 > LabelType : PRE_LABEL > LabelSize : 186 > PoolName : Default > MediaType : FileMedia > PoolType : Backup > HostName : pg82.unixathome.org > Date label written: 05-Oct-2007 15:40 > localhost-sd: append.c:96-2 Begin append device="FileStorage" > (/usr/home/dan/src > /BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:486-2 free_volume TestVolume002 > dev="FileStorage" > /(/usr/ > home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:179-2 List from free_volume: TestVolume001 at > 288090b8 o n > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/d > rive0) > You have messages. > messages > 05-Oct 15:40 localhost-dir: Start Backup JobId 2, > Job=Inc2media.2007-10-05_15.40 > .05 > 05-Oct 15:40 localhost-dir: Using Device "FileStorage" > 05-Oct 15:40 localhost-sd: Wrote label to prelabeled Volume > "TestVolume002" > on d evice > "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > 05-Oct 15:40 localhost-sd: Spooling data ... > 05-Oct 15:40 localhost-sd: Job write elapsed time = 00:00:01, > Transfer rate > = 5. 441 M > bytes/second > 05-Oct 15:40 localhost-sd: Committing spooled data to Volume > "TestVolume002". De > spooling 5,452,979 bytes ... > 05-Oct 15:40 localhost-sd: Despooling elapsed time = 00:00:01, > Transfer rate > = 5 .452 M > bytes/second > 05-Oct 15:40 localhost-sd: Sending spooled attrs to the Director. > Despooling > 56, 433 > bytes ... > 05-Oct 15:40 localhost-dir: Bacula localhost-dir 2.3.6 (30Sep07): > 05-Oct-2007 15 > > :40:44 > > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 2 > Job: Inc2media.2007-10-05_15.40.05 > Backup Level: Incremental, since=2007-10-05 15:40:17 > Client: "localhost-fd" 2.3.6 (30Sep07) > i386-unknown-freebsd7.0 > ,freebsd,7.0-CURRENT > FileSet: "Full Set" 2007-10-05 15:40:15 > Pool: "Default" (From Job resource) > Storage: "File" (From command line) > Scheduled time: 05-Oct-2007 15:40:40 > Start time: 05-Oct-2007 15:40:42 > End time: 05-Oct-2007 15:40:44 > Elapsed time: 2 secs > Priority: 10 > FD Files Written: 181 > SD Files Written: 181 > FD Bytes Written: 5,414,328 (5.414 MB) > SD Bytes Written: 5,441,801 (5.441 MB) > Rate: 2707.2 KB/s > Software Compression: None > VSS: no > Encryption: no > Volume name(s): TestVolume002 > Volume Session Id: 2 > Volume Session Time: 1191598806 > Last Volume Bytes: 5,452,181 (5.452 MB) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: OK > SD termination status: OK > Termination: Backup OK > > 05-Oct 15:40 localhost-dir: Begin pruning Jobs. > 05-Oct 15:40 localhost-dir: No Jobs found to prune. > 05-Oct 15:40 localhost-dir: Begin pruning Files. > 05-Oct 15:40 localhost-dir: No Files found to prune. > 05-Oct 15:40 localhost-dir: End auto prune. > > @# > @# now do a restore > @# > @tee /usr/home/dan/src/BaculaRegressionTesting/tmp/log2.out > setdebug level=51 storage=DDS-4 > Connecting to Storage daemon DDS-4 at localhost:8103 > localhost-sd: cram-md5.c:73-0 send: auth cram-md5 > <[EMAIL PROTECTED] > st-sd> ssl=0 > localhost-sd: dircmd.c:277-0 setdebug_cmd: setdebug=51 trace=-1 > 3000 OK setdebug=51 > restore where=/usr/home/dan/src/BaculaRegressionTesting/tmp/bacula- > restores > sele ct all > done > Automatically selected Client: localhost-fd > Automatically selected FileSet: Full Set > +-------+-------+----------+------------+---------------------+------- > --------+ > > | jobid | level | jobfiles | jobbytes | starttime | > > volumename > > +-------+-------+----------+------------+---------------------+------- > --------+ > > | 1 | F | 5,484 | 68,392,516 | 2007-10-05 15:40:17 | > > TestVolume001 | > > | 2 | I | 181 | 5,414,328 | 2007-10-05 15:40:42 | > > TestVolume002 | > +-------+-------+----------+------------+---------------------+------- > --------+ > You have selected the following JobIds: 1,2 > > Building directory tree for JobId 1 ... > +++++++++++++++++++++++++++++++++++++++ > +++++++ > Building directory tree for JobId 2 ... > 2 Jobs, 5,115 files inserted into the tree and marked for extraction. > Bootstrap records written to > /usr/home/dan/src/BaculaRegressionTesting/working/l > ocalhost-dir.restore.1.bsr > > The job will require the following > Volume(s) Storage(s) SD Device(s) > ====================================================================== > ===== > > TestVolume001 DDS-4 DDS-4 > TestVolume002 File FileStorage > > > 5,484 files selected to be restored. > > Run Restore job > JobName: RestoreFiles > Bootstrap: > /usr/home/dan/src/BaculaRegressionTesting/working/localhost-dir > .restore.1.bsr > Where: > /usr/home/dan/src/BaculaRegressionTesting/tmp/bacula-restores > Replace: always > FileSet: Full Set > Backup Client: localhost-fd > Restore Client: localhost-fd > Storage: DDS-4 > When: 2007-10-05 15:40:45 > Catalog: MyCatalog > Priority: 10 > OK to run? (yes/mod/no): yes > Job queued. JobId=3 > wait > localhost-sd: cram-md5.c:73-0 send: auth cram-md5 > <[EMAIL PROTECTED] > st-sd> ssl=0 > localhost-sd: reserve.c:583-3 <dird: use storage= media_type=DDS-4 > pool_name=Def > ault > pool_type=Backup append=0 copy=0 stripe=0 > localhost-sd: reserve.c:612-3 <dird device: use device=DDS-4 > localhost-sd: reserve.c:628-3 Storage= media_type=DDS-4 pool=Default > pool_type=B > ackup > append=0 > localhost-sd: reserve.c:630-3 Device=DDS-4 > localhost-sd: reserve.c:708-3 PrefMnt=1 exact=1 suitable=0 chgronly=0 > any=0 > localhost-sd: reserve.c:815-3 PrefMnt=1 exact=1 suitable=0 chgronly=0 > localhost-sd: reserve.c:970-3 search res for DDS-4 > localhost-sd: reserve.c:973-3 Try match changer res=DDS-4 > localhost-sd: reserve.c:978-3 Try changer device Drive-0 > localhost-sd: reserve.c:1036-3 chk MediaType device=DDS-4 request=DDS- > 4 > localhost-sd: reserve.c:1059-3 try reserve Drive-0 > localhost-sd: reserve.c:1194-3 Inc reserve=1 dev="Drive-0" > (/usr/home/dan/src/Ba > culaRegressionTesting/tmp/disk-changer/drive0) 2870c018 > localhost-sd: reserve.c:1131-3 Read reserved=1 dev_name=DDS-4 > mediatype=DDS-4 po > ol=Default ok=1 > localhost-sd: reserve.c:1143-3 >dird: 3000 OK use device device=Drive- > 0 > localhost-sd: reserve.c:989-3 Device Drive-0 reserved=1 for read. > localhost-sd: reserve.c:944-3 available device found=DDS-4 > localhost-sd: job.c:177-3 RestoreFiles.2007-10-05_15.40.06 waiting > 1800 sec > for FD to > contact > SD key=KKAA-FDOJ-FOND-LDKO-HMAI-DFOI-PNKP-IHBP > localhost-sd: cram-md5.c:73-0 send: auth cram-md5 > <[EMAIL PROTECTED] > t-sd> ssl=0 > localhost-sd: fd_cmds.c:360-3 === Bootstrap file === > localhost-sd: fd_cmds.c:362-3 Volume="TestVolume001" > localhost-sd: fd_cmds.c:362-3 MediaType="DDS-4" > localhost-sd: fd_cmds.c:362-3 Device="DDS-4" > localhost-sd: fd_cmds.c:362-3 Slot=1 > localhost-sd: fd_cmds.c:362-3 VolSessionId=1 > localhost-sd: fd_cmds.c:362-3 VolSessionTime=1191598806 > localhost-sd: fd_cmds.c:362-3 VolFile=0 > localhost-sd: fd_cmds.c:362-3 VolBlock=218-69541989 > localhost-sd: fd_cmds.c:362-3 FileIndex=1-1984 > localhost-sd: fd_cmds.c:362-3 FileIndex=1987-1988 > localhost-sd: fd_cmds.c:362-3 FileIndex=1993-1994 > localhost-sd: fd_cmds.c:362-3 FileIndex=1996 > localhost-sd: fd_cmds.c:362-3 FileIndex=2019 > localhost-sd: fd_cmds.c:362-3 FileIndex=2027 > localhost-sd: fd_cmds.c:362-3 FileIndex=2031 > localhost-sd: fd_cmds.c:362-3 FileIndex=2033 > localhost-sd: fd_cmds.c:362-3 FileIndex=2035-2037 > localhost-sd: fd_cmds.c:362-3 FileIndex=2079-3510 > localhost-sd: fd_cmds.c:362-3 FileIndex=3512 > localhost-sd: fd_cmds.c:362-3 FileIndex=3515 > localhost-sd: fd_cmds.c:362-3 FileIndex=3517 > localhost-sd: fd_cmds.c:362-3 FileIndex=3520-3521 > localhost-sd: fd_cmds.c:362-3 FileIndex=3526 > localhost-sd: fd_cmds.c:362-3 FileIndex=3528 > localhost-sd: fd_cmds.c:362-3 FileIndex=3532-3535 > localhost-sd: fd_cmds.c:362-3 FileIndex=3541-3543 > localhost-sd: fd_cmds.c:362-3 FileIndex=3546-3547 > localhost-sd: fd_cmds.c:362-3 FileIndex=3549 > localhost-sd: fd_cmds.c:362-3 FileIndex=3551 > localhost-sd: fd_cmds.c:362-3 FileIndex=3554-3555 > localhost-sd: fd_cmds.c:362-3 FileIndex=3558 > localhost-sd: fd_cmds.c:362-3 FileIndex=3562 > localhost-sd: fd_cmds.c:362-3 FileIndex=3564-3565 > localhost-sd: fd_cmds.c:362-3 FileIndex=3569-3571 > localhost-sd: fd_cmds.c:362-3 FileIndex=3573-3574 > localhost-sd: fd_cmds.c:362-3 FileIndex=3584-3585 > localhost-sd: fd_cmds.c:362-3 FileIndex=3587 > localhost-sd: fd_cmds.c:362-3 FileIndex=3589 > localhost-sd: fd_cmds.c:362-3 FileIndex=3591 > localhost-sd: fd_cmds.c:362-3 FileIndex=3593-3594 > localhost-sd: fd_cmds.c:362-3 FileIndex=3597-3599 > localhost-sd: fd_cmds.c:362-3 FileIndex=3649-5484 > localhost-sd: fd_cmds.c:362-3 Count=5303 > localhost-sd: fd_cmds.c:362-3 Volume="TestVolume002" > localhost-sd: fd_cmds.c:362-3 MediaType="FileMedia" > localhost-sd: fd_cmds.c:362-3 Device="FileStorage" > localhost-sd: fd_cmds.c:362-3 VolSessionId=2 > localhost-sd: fd_cmds.c:362-3 VolSessionTime=1191598806 > localhost-sd: fd_cmds.c:362-3 VolFile=0 > localhost-sd: fd_cmds.c:362-3 VolBlock=222-5452180 > localhost-sd: fd_cmds.c:362-3 FileIndex=1-181 > localhost-sd: fd_cmds.c:362-3 Count=181 > localhost-sd: fd_cmds.c:366-3 === end bootstrap file === > Next : 0x288171e8 > Root bsr : 0x28817178 > VolumeName : TestVolume001 > MediaType : DDS-4 > Device : DDS-4 > Slot : 1 > SessId : 1 > SessTime : 1191598806 > VolFile : 0-0 > VolBlock : 218-69541989 > FileIndex : 1-1984 > FileIndex : 1987-1988 > FileIndex : 1993-1994 > FileIndex : 1996 > FileIndex : 2019 > FileIndex : 2027 > FileIndex : 2031 > FileIndex : 2033 > FileIndex : 2035-2037 > FileIndex : 2079-3510 > FileIndex : 3512 > FileIndex : 3515 > FileIndex : 3517 > FileIndex : 3520-3521 > FileIndex : 3526 > FileIndex : 3528 > FileIndex : 3532-3535 > FileIndex : 3541-3543 > FileIndex : 3546-3547 > FileIndex : 3549 > FileIndex : 3551 > FileIndex : 3554-3555 > FileIndex : 3558 > FileIndex : 3562 > FileIndex : 3564-3565 > FileIndex : 3569-3571 > FileIndex : 3573-3574 > FileIndex : 3584-3585 > FileIndex : 3587 > FileIndex : 3589 > FileIndex : 3591 > FileIndex : 3593-3594 > FileIndex : 3597-3599 > FileIndex : 3649-5484 > count : 5303 > found : 0 > done : no > positioning : 1 > fast_reject : 1 > > Next : 0x0 > Root bsr : 0x28817178 > VolumeName : TestVolume002 > MediaType : FileMedia > Device : FileStorage > Slot : 0 > SessId : 2 > SessTime : 1191598806 > VolFile : 0-0 > VolBlock : 222-5452180 > FileIndex : 1-181 > count : 181 > found : 0 > done : no > positioning : 0 > fast_reject : 0 > localhost-sd: read.c:59-3 Start read data. > localhost-sd: acquire.c:108-3 MediaType dcr=DDS-4 dev=DDS-4 > localhost-sd: acquire.c:210-3 opened dev "Drive-0" > (/usr/home/dan/src/BaculaRegr > essionTesting/tmp/disk-changer/drive0) OK > localhost-sd: acquire.c:213-3 calling read-vol-label > localhost-sd: reserve.c:311-3 reserve_volume TestVolume001 > localhost-sd: reserve.c:179-3 List from begin reserve_volume: > TestVolume001 > at 2 88090b8 > on > device "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/drive0) > localhost-sd: reserve.c:330-3 OK, vol=TestVolume001 on device. > localhost-sd: reserve.c:179-3 List from end new volume: TestVolume001 > at > 288090b 8 on > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-change > r/drive0) > > Volume Label: > Id : Bacula 1.0 immortal > VerNo : 11 > VolName : TestVolume001 > PrevVolName : > VolFile : 0 > LabelType : VOL_LABEL > LabelSize : 182 > PoolName : Default > MediaType : DDS-4 > PoolType : Backup > HostName : pg82.unixathome.org > Date label written: 05-Oct-2007 15:40 > localhost-sd: acquire.c:293-3 Dec reserve=0 dev="Drive-0" > (/usr/home/dan/src/Bac > ulaRegressionTesting/tmp/disk-changer/drive0) > localhost-sd: acquire.c:108-3 MediaType dcr=FileMedia dev=DDS-4 > localhost-sd: acquire.c:119-3 Changing device. Want Media > Type="FileMedia" > have= "DDS- > 4" > device="Drive-0" > (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-changer/d > rive0) > localhost-sd: reserve.c:970-3 search res for FileStorage > localhost-sd: reserve.c:973-3 Try match changer res=DDS-4 > localhost-sd: reserve.c:999-3 Try match res=Drive-0 > localhost-sd: reserve.c:999-3 Try match res=FileStorage > localhost-sd: reserve.c:1036-3 chk MediaType device=FileMedia > request=FileMedia > localhost-sd: reserve.c:1059-3 try reserve FileStorage > localhost-sd: reserve.c:1194-3 Inc reserve=1 dev="FileStorage" > (/usr/home/dan/sr > c/BaculaRegressionTesting/tmp) 2870c818 > localhost-sd: reserve.c:1131-3 Read reserved=1 dev_name=FileStorage > mediatype=Fi > leMedia pool=Default ok=1 > localhost-sd: reserve.c:1012-3 Device FileStorage reserved=1 for > read. > localhost-sd: acquire.c:154-3 Media Type change. New device > "FileStorage" > (/usr > /home/dan/src/BaculaRegressionTesting/tmp) chosen. > localhost-sd: acquire.c:210-3 opened dev "FileStorage" > /(/usr/home/dan/src/Bacula > RegressionTesting/tmp) OK > localhost-sd: acquire.c:213-3 calling read-vol-label > localhost-sd: reserve.c:311-3 reserve_volume TestVolume002 > localhost-sd: reserve.c:179-3 List from begin reserve_volume: > TestVolume001 > at 2 88090b8 > on > device "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/drive0) > localhost-sd: reserve.c:236-3 new Vol=TestVolume002 at 28809958 > dev="FileStorage > " > (/usr/home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:179-3 List from end new volume: TestVolume001 > at > 288090b 8 on > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-change > r/drive0) > localhost-sd: reserve.c:179-3 List from end new volume: TestVolume002 > at > 2880995 8 on > device > "FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp) > > Volume Label: > Id : Bacula 1.0 immortal > VerNo : 11 > VolName : TestVolume002 > PrevVolName : > VolFile : 0 > LabelType : VOL_LABEL > LabelSize : 186 > PoolName : Default > MediaType : FileMedia > PoolType : Backup > HostName : pg82.unixathome.org > Date label written: 05-Oct-2007 15:40 > localhost-sd: acquire.c:293-3 Dec reserve=0 dev="FileStorage" > (/usr/home/dan/src > /BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:486-3 free_volume TestVolume002 > dev="FileStorage" > /(/usr/ > home/dan/src/BaculaRegressionTesting/tmp) > localhost-sd: reserve.c:179-3 List from free_volume: TestVolume001 at > 288090b8 o n > device > "Drive-0" (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk- > changer/d > rive0) > localhost-sd: read.c:96-3 Done reading. > You have messages. > messages > 05-Oct 15:40 localhost-dir: Start Restore Job > RestoreFiles.2007-10-05_15.40.06 > 05-Oct 15:40 localhost-dir: Using Device "Drive-0" > 05-Oct 15:40 localhost-sd: 3301 Issuing autochanger "loaded? drive 0" > command. > 05-Oct 15:40 localhost-sd: 3302 Autochanger "loaded? drive 0", result > is > Slot 1. > 05-Oct 15:40 localhost-sd: 3301 Issuing autochanger "loaded? drive 0" > command. > 05-Oct 15:40 localhost-sd: 3302 Autochanger "loaded? drive 0", result > is > Slot 1. > 05-Oct 15:40 localhost-sd: Ready to read from volume "TestVolume001" > on > device " > Drive-0" > (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-changer/drive0). > 05-Oct 15:40 localhost-sd: Forward spacing Volume "TestVolume001" to > file:block > 0:218. > 05-Oct 15:41 localhost-sd: End of file 0 on device "Drive-0" > (/usr/home/dan/src/ > BaculaRegressionTesting/tmp/disk-changer/drive0), Volume > "TestVolume001" > 05-Oct 15:41 localhost-sd: End of Volume at file 0 on device "Drive- > 0" > (/usr/hom > e/dan/src/BaculaRegressionTesting/tmp/disk-changer/drive0), Volume > "TestVolume00 > 1" > 05-Oct 15:41 localhost-sd: acquire.c:116 Changing device. Want Media > Type="FileM > edia" > have="DDS-4" > device="Drive-0" > (/usr/home/dan/src/BaculaRegressionTesting/tmp/disk-changer/d > rive0) > 05-Oct 15:41 localhost-sd: Media Type change. New device > "FileStorage" > (/usr/ho > me/dan/src/BaculaRegressionTesting/tmp) chosen. > 05-Oct 15:41 localhost-sd: Ready to read from volume "TestVolume002" > on > device " > FileStorage" (/usr/home/dan/src/BaculaRegressionTesting/tmp). > 05-Oct 15:41 localhost-sd: Forward spacing Volume "TestVolume002" to > file:block > 0:222. > 05-Oct 15:41 localhost-sd: End of Volume at file 0 on device > "FileStorage" > (/usr > /home/dan/src/BaculaRegressionTesting/tmp), Volume "TestVolume002" > 05-Oct 15:41 localhost-sd: End of all volumes. > 05-Oct 15:41 localhost-dir: Bacula localhost-dir 2.3.6 (30Sep07): > 05-Oct-2007 15 > > :41:03 > > Build OS: i386-unknown-freebsd7.0 freebsd 7.0-CURRENT > JobId: 3 > Job: RestoreFiles.2007-10-05_15.40.06 > Restore Client: localhost-fd > Start time: 05-Oct-2007 15:40:47 > End time: 05-Oct-2007 15:41:03 > Files Expected: 5,484 > Files Restored: 5,484 > Bytes Restored: 68,392,516 > Rate: 4274.5 KB/s > FD Errors: 0 > FD termination status: OK > SD termination status: OK > Termination: Restore OK > > 05-Oct 15:41 localhost-dir: Begin pruning Jobs. > 05-Oct 15:41 localhost-dir: No Jobs found to prune. > 05-Oct 15:41 localhost-dir: Begin pruning Files. > 05-Oct 15:41 localhost-dir: No Files found to prune. > 05-Oct 15:41 localhost-dir: End auto prune. > > @tee > quit > localhost-sd: cram-md5.c:73-0 send: auth cram-md5 > <[EMAIL PROTECTED] > st-sd> ssl=0 > Pool Maxsize Maxused Inuse > NoPool 256 3 0 > NAME 130 0 0 > FNAME 256 11 0 > MSG 65636 10 0 > EMSG 1024 1 0 > > localhost-sd: stored.c:587-0 Term device > /usr/home/dan/src/BaculaRegressionTesti > ng/tmp/disk-changer/drive0 > localhost-sd: stored.c:587-0 Term device > /usr/home/dan/src/BaculaRegressionTesti > ng/tmp > Pool Maxsize Maxused Inuse > NoPool 256 12 0 > NAME 130 10 0 > FNAME 256 4 0 > MSG 65636 8 0 > EMSG 1024 3 0 > > ===== incremental-2media OK 15:41:19 ===== ------------------------------------------------------------------------- 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-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-devel
