From: Georg A. <gal...@la...> - 2005-11-21 23:03:42
|
Hi, I have managed to crash btape with a fill test (two tapes version). Problem description: I am currently in the process of setting up bacula on our backup server. I am using a ADIC FastStor-2 autoloader equipped with a HP LTO-Ultrium-1 drive. I've passed the test command with autoloader tets successfully after a bit of tweaking. I was just happily seeing the fill test reaching the 100 GB limit of the LTO tape, but btape segfaulted right after reading the last block back in. See the attached screendump. Notice the dumb load commands entered before I started the fill command. Maybe this confused btape? I've just re-compiled/-installed the bacula-server port with debugging symbols using make CFLAGS='-g'. I will now try to reproduce this under gdb. What else should I do other than a bt after the crash? Any ideas? Regads, Georg =========== System info =========== asterix> uname -a FreeBSD asterix.las-cad.local 4.11-RELEASE-p13 FreeBSD 4.11-RELEASE-p13 #10: Mon Oct 31 14:46:11 CET 2005 ro...@as...s-cad.local:/usr/obj/usr/src/sys/ASTERIX i386 asterix# camcontrol devlist <ICP Host Drive #00 > at scbus4 target 0 lun 0 (pass0,da0) <ICP Host Drive #03 > at scbus4 target 3 lun 0 (pass1,da1) <ADIC FastStor 2 A12r> at scbus5 target 0 lun 0 (pass2) <HP Ultrium 1-SCSI E33A> at scbus5 target 5 lun 0 (pass3,sa0) asterix# mt geteotmodel /dev/nsa0: the model is 1 filemark at EOT asterix# pkg_info | grep bacula bacula-client-1.38.1 The network backup solution (client) bacula-server-1.38.1 The network backup solution (server) ==================== bacula device config ==================== Device { Name = Ultrium1-0 Drive Index = 0 Media Type = Ultrium1 Archive Device = /dev/nsa0 Changer Device = /dev/pass2 AutomaticMount = yes; # when device opened, read it AlwaysOpen = yes; RemovableMedia = yes; RandomAccess = no; AutoChanger = yes; Hardware End of Medium = no; # Enable the Alert command only if you have the mtx package loaded Alert Command = "sh -c 'tapeinfo -f /dev/pass3 |grep TapeAlert|cat'" } Autochanger { Name = FastStor2 Device = Ultrium1-0 Changer Device = /dev/pass2 Changer Command = "/usr/local/share/bacula/mtx-changer %c %o %S %a %d" } ========== Screendump ========== asterix# btape -c bacula-sd.conf /dev/nsa0 Tape block granularity is 1024 bytes. btape: butil.c:266 Using device: "/dev/nsa0" for writing. 21-Nov 19:02 btape: 3301 Issuing autochanger "loaded drive 0" command. 21-Nov 19:02 btape: 3302 Autochanger "loaded drive 0", result is Slot 1. 21-Nov 19:02 btape: 3301 Issuing autochanger "loaded drive 0" command. 21-Nov 19:02 btape: 3302 Autochanger "loaded drive 0", result is Slot 1. btape: btape.c:338 open device "Ultrium1-0" (/dev/nsa0): OK *load 2 btape: btape.c:424 Bad status from load. ERR=dev.c:1070 ioctl MTLOAD error on "Ultrium1-0" (/dev/nsa0). ERR=Resource temporarily unavailable. *h Copyright (C) 2000-2005 Kern Sibbald. [--SNIP--] qfill quick fill command *help load Copyright (C) 2000-2005 Kern Sibbald. [--SNIP--] qfill quick fill command *load btape: btape.c:424 Bad status from load. ERR=dev.c:1070 ioctl MTLOAD error on "Ultrium1-0" (/dev/nsa0). ERR=Resource temporarily unavailable. *fill This command simulates Bacula writing to a tape. [--SNIP--] This may take a long time -- hours! ... Do you want to run the simplified test (s) with one tape or the complete multiple tape (m) test: (s/m) m Multiple tape test selected. Wrote Volume label for volume "TestVolume1". Wrote Start of Session label. Begin writing Bacula records to first tape ... Wrote blk_block=5000, dev_blk_num=4999 VolBytes=322,495,472 rate=14021.5 KB/s Wrote blk_block=10000, dev_blk_num=9999 VolBytes=645,055,424 rate=15001.3 KB/s Wrote blk_block=15000, dev_blk_num=14999 VolBytes=967,615,368 rate=15119.0 KB/s Flush block, write EOF [--SNIP--] Flush block, write EOF Wrote blk_block=1640000, dev_blk_num=5000 VolBytes=105,799,598,176 rate=14528.9 KB/s Wrote blk_block=1645000, dev_blk_num=10000 VolBytes=106,122,158,120 rate=14533.3 KB/s Wrote blk_block=1650000, dev_blk_num=15000 VolBytes=106,444,718,064 rate=14535.7 KB/s Flush block, write EOF Wrote blk_block=1655000, dev_blk_num=5000 VolBytes=106,767,278,016 rate=14532.1 KB/s 21-Nov 21:05 btape: End of Volume "TestVolume1" at 111:6057 on device "Ultrium1-0" (/dev/nsa0). Write of 64512 bytes got 0. 21-Nov 21:05 btape: Re-read of last block succeeded. btape: btape.c:2295 Last block at: 111:6056 this_dev_block_num=6057 btape: btape.c:2329 End of tape 111:0. VolumeCapacity=106,835,531,696. Write rate = 14517.7 KB/s 21-Nov 21:05 btape: End of medium on Volume "TestVolume1" Bytes=106,835,531,696 Blocks=1,656,057 at 21-Nov-2005 21:05. 21-Nov 21:06 btape: ABORTING due to ERROR in bsys.c:382 Mutex unlock failure. ERR=Invalid argument 21-Nov 21:06 btape: Fatal Error because: Bacula interrupted by signal 11: Segmentation violation Kaboom! btape, btape got signal 11. Attempting traceback. Kaboom! exepath=/usr/local/etc Calling: /usr/local/etc/btraceback /usr/local/etc/btape 0 execv: /usr/local/etc/btraceback failed: ERR=No such file or directory asterix# -- Georg Altmann <gal...@la...> LAS-CAD GmbH, Munich, Germany http://www.las-cad.com |
From: Kern S. <ke...@si...> - 2005-11-22 08:03:31
|
Hello, Apply the patch in bug report #492 and it will fix your problem. On Tuesday 22 November 2005 00:03, Georg Altmann wrote: > Hi, > > I have managed to crash btape with a fill test (two tapes version). > > Problem description: > I am currently in the process of setting up bacula on our backup server. I > am using a ADIC FastStor-2 autoloader equipped with a HP LTO-Ultrium-1 > drive. I've passed the test command with autoloader tets successfully > after a bit of tweaking. > I was just happily seeing the fill test reaching the 100 GB limit of the > LTO tape, but btape segfaulted right after reading the last block back in. > See the attached screendump. Notice the dumb load commands entered before I > started the fill command. Maybe this confused btape? > > I've just re-compiled/-installed the bacula-server port with debugging > symbols using make CFLAGS='-g'. I will now try to reproduce this under gdb. > What else should I do other than a bt after the crash? > > Any ideas? > > Regads, > Georg > > =========== > System info > =========== > > asterix> uname -a > FreeBSD asterix.las-cad.local 4.11-RELEASE-p13 FreeBSD 4.11-RELEASE-p13 > #10: Mon Oct 31 14:46:11 CET 2005 > ro...@as...s-cad.local:/usr/obj/usr/src/sys/ASTERIX i386 > > asterix# camcontrol devlist > <ICP Host Drive #00 > at scbus4 target 0 lun 0 (pass0,da0) > <ICP Host Drive #03 > at scbus4 target 3 lun 0 (pass1,da1) > <ADIC FastStor 2 A12r> at scbus5 target 0 lun 0 (pass2) > <HP Ultrium 1-SCSI E33A> at scbus5 target 5 lun 0 (pass3,sa0) > > asterix# mt geteotmodel > /dev/nsa0: the model is 1 filemark at EOT > > asterix# pkg_info | grep bacula > bacula-client-1.38.1 The network backup solution (client) > bacula-server-1.38.1 The network backup solution (server) > > > > > ==================== > bacula device config > ==================== > > Device { > Name = Ultrium1-0 > Drive Index = 0 > Media Type = Ultrium1 > Archive Device = /dev/nsa0 > Changer Device = /dev/pass2 > AutomaticMount = yes; # when device opened, read it > AlwaysOpen = yes; > RemovableMedia = yes; > RandomAccess = no; > AutoChanger = yes; > Hardware End of Medium = no; > # Enable the Alert command only if you have the mtx package loaded > Alert Command = "sh -c 'tapeinfo -f /dev/pass3 |grep TapeAlert|cat'" > } > > Autochanger { > Name = FastStor2 > Device = Ultrium1-0 > Changer Device = /dev/pass2 > Changer Command = "/usr/local/share/bacula/mtx-changer %c %o %S %a %d" > } > > > > > ========== > Screendump > ========== > > asterix# btape -c bacula-sd.conf /dev/nsa0 > Tape block granularity is 1024 bytes. > btape: butil.c:266 Using device: "/dev/nsa0" for writing. > 21-Nov 19:02 btape: 3301 Issuing autochanger "loaded drive 0" command. > 21-Nov 19:02 btape: 3302 Autochanger "loaded drive 0", result is Slot 1. > 21-Nov 19:02 btape: 3301 Issuing autochanger "loaded drive 0" command. > 21-Nov 19:02 btape: 3302 Autochanger "loaded drive 0", result is Slot 1. > btape: btape.c:338 open device "Ultrium1-0" (/dev/nsa0): OK > *load 2 > btape: btape.c:424 Bad status from load. ERR=dev.c:1070 ioctl MTLOAD error > on "Ultrium1-0" (/dev/nsa0). ERR=Resource temporarily unavailable. > > *h > Copyright (C) 2000-2005 Kern Sibbald. > [--SNIP--] > qfill quick fill command > > *help load > Copyright (C) 2000-2005 Kern Sibbald. > [--SNIP--] > qfill quick fill command > > *load > btape: btape.c:424 Bad status from load. ERR=dev.c:1070 ioctl MTLOAD error > on "Ultrium1-0" (/dev/nsa0). ERR=Resource temporarily unavailable. > > *fill > > This command simulates Bacula writing to a tape. > [--SNIP--] > This may take a long time -- hours! ... > > Do you want to run the simplified test (s) with one tape > or the complete multiple tape (m) test: (s/m) m > Multiple tape test selected. > Wrote Volume label for volume "TestVolume1". > Wrote Start of Session label. > Begin writing Bacula records to first tape ... > Wrote blk_block=5000, dev_blk_num=4999 VolBytes=322,495,472 rate=14021.5 > KB/s > Wrote blk_block=10000, dev_blk_num=9999 VolBytes=645,055,424 rate=15001.3 > KB/s > Wrote blk_block=15000, dev_blk_num=14999 VolBytes=967,615,368 rate=15119.0 > KB/s > Flush block, write EOF > [--SNIP--] > Flush block, write EOF > Wrote blk_block=1640000, dev_blk_num=5000 VolBytes=105,799,598,176 > rate=14528.9 KB/s > Wrote blk_block=1645000, dev_blk_num=10000 VolBytes=106,122,158,120 > rate=14533.3 KB/s > Wrote blk_block=1650000, dev_blk_num=15000 VolBytes=106,444,718,064 > rate=14535.7 KB/s > Flush block, write EOF > Wrote blk_block=1655000, dev_blk_num=5000 VolBytes=106,767,278,016 > rate=14532.1 KB/s > 21-Nov 21:05 btape: End of Volume "TestVolume1" at 111:6057 on device > "Ultrium1-0" (/dev/nsa0). Write of 64512 bytes got 0. > 21-Nov 21:05 btape: Re-read of last block succeeded. > btape: btape.c:2295 Last block at: 111:6056 this_dev_block_num=6057 > btape: btape.c:2329 End of tape 111:0. VolumeCapacity=106,835,531,696. > Write rate = 14517.7 KB/s > 21-Nov 21:05 btape: End of medium on Volume "TestVolume1" > Bytes=106,835,531,696 Blocks=1,656,057 at 21-Nov-2005 21:05. > 21-Nov 21:06 btape: ABORTING due to ERROR in bsys.c:382 > Mutex unlock failure. ERR=Invalid argument > 21-Nov 21:06 btape: Fatal Error because: Bacula interrupted by signal 11: > Segmentation violation > Kaboom! btape, btape got signal 11. Attempting traceback. > Kaboom! exepath=/usr/local/etc > Calling: /usr/local/etc/btraceback /usr/local/etc/btape 0 > execv: /usr/local/etc/btraceback failed: ERR=No such file or directory > asterix# > > > -- > Georg Altmann <gal...@la...> > LAS-CAD GmbH, Munich, Germany > http://www.las-cad.com > > > > > ------------------------------------------------------- > This SF.Net email is sponsored by the JBoss Inc. Get Certified Today > Register for a JBoss Training Course. Free Certification Exam > for All Training Attendees Through End of 2005. For more info visit: > http://ads.osdn.com/?ad_id=7628&alloc_id=16845&op=click > _______________________________________________ > Bacula-devel mailing list > Bac...@li... > https://lists.sourceforge.net/lists/listinfo/bacula-devel -- Best regards, Kern ("> /\ V_V |