vtltape segfault with gitversion including commit from March 28
Locked
 
|
Hi Mark,
I have updated the git version up until 30 march and now I get a segfault when running bacula, at the moment when it wants to read from the tape drive. This did not happen a few days ago. Here is the vtlcmd 11 verbose output in messages: Mar 30 18:58:37 moonlight vtltape[8446]: processMessageQ(): Verbose: enabled at level 3 Mar 30 18:58:53 moonlight vtltape[8446]: CDB (190) (delay 151200): 00 00 00 00 00 00 Mar 30 18:58:53 moonlight vtltape[8446]: mkSenseBuf(): SENSE [Key/ASC/ASCQ] [06 29 00] Mar 30 18:58:53 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (190), sz: 0, sam_status: 2 Mar 30 18:58:53 moonlight vtltape[8446]: completeSCSICommand(): [Key/ASC/ASCQ] [06 29 00] Mar 30 18:58:53 moonlight vtltape[8446]: CDB (191) (delay 405): 00 00 00 00 00 00 Mar 30 18:58:53 moonlight vtltape[8446]: mkSenseBuf(): SENSE [Key/ASC/ASCQ] [02 3a 00] Mar 30 18:58:53 moonlight vtltape[8446]: ssc_tur(): Test Unit Ready (191) ** : No, No tape loaded Mar 30 18:58:53 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (191), sz: 0, sam_status: 2 Mar 30 18:58:53 moonlight vtltape[8446]: completeSCSICommand(): [Key/ASC/ASCQ] [02 3a 00] Mar 30 18:59:19 moonlight vtltape[8446]: processMessageQ(): Sender id: 10, msg : lload ML0003L3 Mar 30 18:59:19 moonlight vtltape[8446]: load_tape(): Opening media: ML0003L3 Mar 30 18:59:19 moonlight vtltape[8446]: read_header(): Reading header 38064 at offset 1990616687, type: FILEMARK, size: 0 Mar 30 18:59:19 moonlight vtltape[8446]: read_header(): Reading header 0 at offset 0, type: DATA, size: 64512 Mar 30 18:59:19 moonlight vtltape[8446]: hp_media_load(): +++ Trace +++ load Mar 30 18:59:19 moonlight vtltape[8446]: lookup_media_type(): looking for media type 0x05 Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Media type 'LTO3' loaded with S/No. : ML0003L3_1354359998 Mar 30 18:59:19 moonlight vtltape[8446]: clear_ult_WORM(): +++ Trace mode pages at 0x6263c0 +++ Mar 30 18:59:19 moonlight vtltape[8446]: lookup_pcode(): Looking for: Page/subpage (1d/00) Mar 30 18:59:19 moonlight vtltape[8446]: lookup_pcode(): Found "Medium Configuration" -> Page/subpage (1d/00) Mar 30 18:59:19 moonlight vtltape[8446]: clear_WORM(): l: 0x6263c0, m: 0x1670920, m->pcodePointer: 0x1670960 Mar 30 18:59:19 moonlight vtltape[8446]: mkSenseBuf(): SENSE [Key/ASC/ASCQ] [06 28 00] Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Previous unload was not clean Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Tape capacity: 10737418240 + Early Warning 2097152 Mar 30 18:59:19 moonlight vtltape[8446]: updateMAM(): updateMAM(load) Mar 30 18:59:19 moonlight vtltape[8446]: check_media_can_load(): Looking for media_type: 0x05 Mar 30 18:59:19 moonlight vtltape[8446]: check_media_can_load(): testing against m_detail->media_type (0x01) Mar 30 18:59:19 moonlight vtltape[8446]: check_media_can_load(): testing against m_detail->media_type (0x02) Mar 30 18:59:19 moonlight vtltape[8446]: check_media_can_load(): testing against m_detail->media_type (0x03) Mar 30 18:59:19 moonlight vtltape[8446]: check_media_can_load(): testing against m_detail->media_type (0x04) Mar 30 18:59:19 moonlight vtltape[8446]: check_media_can_load(): testing against m_detail->media_type (0x05) Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Load Capability: 0x02 Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Mounting READ/WRITE Mar 30 18:59:19 moonlight vtltape[8446]: lookup_log_pg(): Looking for: log page 0x2e Mar 30 18:59:19 moonlight vtltape[8446]: lookup_log_pg(): Tape Alert (0x2e) Mar 30 18:59:19 moonlight vtltape[8446]: update_TapeAlert(): Setting TapeAlert flags 0x00020000 00000000 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_log_pg(): Looking for: log page 0x0c Mar 30 18:59:19 moonlight vtltape[8446]: lookup_log_pg(): Sequential Access (0x0c) Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Media is writable Mar 30 18:59:19 moonlight vtltape[8446]: lookup_mode_media_type(): looking for mode media type for 0x05 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_mode_media_type(): LTO1 : 0x01 mode media type 0x00 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_mode_media_type(): LTO1 Clean : 0x02 mode media type 0x00 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_mode_media_type(): LTO2 : 0x03 mode media type 0x00 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_mode_media_type(): LTO2 Clean : 0x04 mode media type 0x00 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_mode_media_type(): LTO3 : 0x05 mode media type 0x00 Mar 30 18:59:19 moonlight vtltape[8446]: lookup_density_name(): looking for density type 0x44 Mar 30 18:59:19 moonlight vtltape[8446]: loadTape(): Setting MediumDensityCode to LTO3 (0x44) Media type: 0x00 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (205) (delay 146405): 00 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_tur(): Test Unit Ready (205) ** : Yes Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (205), sz: 0, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (206) (delay 405): 05 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_read_block_limits(): Read block limits (206) ** Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (206), sz: 6, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (207) (delay 405): 1a 00 00 00 0c 00 Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): MODE SENSE (207) ** Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Mode Sense 6 byte version Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Page Control : Current values(0x00) Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Page/Subpage Code: 0x00/0x00 Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Report Block Descriptor Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Allocation len : 12 Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (207), sz: 12, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (208) (delay 1605): 00 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_tur(): Test Unit Ready (208) ** : Yes Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (208), sz: 0, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (209) (delay 405): 05 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_read_block_limits(): Read block limits (209) ** Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (209), sz: 6, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (210) (delay 405): 1a 00 00 00 0c 00 Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): MODE SENSE (210) ** Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Mode Sense 6 byte version Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Page Control : Current values(0x00) Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Page/Subpage Code: 0x00/0x00 Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Report Block Descriptor Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Allocation len : 12 Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (210), sz: 12, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (211) (delay 405): 01 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_rewind(): Rewinding (211) ** Mar 30 18:59:20 moonlight vtltape[8446]: read_header(): Reading header 0 at offset 0, type: DATA, size: 64512 Mar 30 18:59:20 moonlight vtltape[8446]: rewind_tape(): Media is writable Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (211), sz: 0, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (212) (delay 805): 00 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_tur(): Test Unit Ready (212) ** : Yes Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (212), sz: 0, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (213) (delay 405): 05 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_read_block_limits(): Read block limits (213) ** Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (213), sz: 6, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (214) (delay 405): 1a 00 00 00 0c 00 Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): MODE SENSE (214) ** Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Mode Sense 6 byte version Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Page Control : Current values(0x00) Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Page/Subpage Code: 0x00/0x00 Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Report Block Descriptor Mar 30 18:59:20 moonlight vtltape[8446]: spc_mode_sense(): Allocation len : 12 Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (214), sz: 12, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (215) (delay 405): 1e 00 00 00 01 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_allow_prevent_removal(): Prevent MEDIA removal (215) ** Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (215), sz: 0, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (216) (delay 805): 15 10 00 00 0c 00 Mar 30 18:59:20 moonlight vtltape[8446]: retrieve_CDB_data(): retrieving 12 bytes from kernel Mar 30 18:59:20 moonlight vtltape[8446]: ssc_mode_select(): MODE SELECT (216) ** Mar 30 18:59:20 moonlight vtltape[8446]: ssc_mode_select(): Save Pages: 0, Page Format: 1 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_mode_select(): Save pages bit not set. Ignoring page data Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (216), sz: 12, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (217) (delay 405): 01 00 00 00 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_rewind(): Rewinding (217) ** Mar 30 18:59:20 moonlight vtltape[8446]: read_header(): Reading header 0 at offset 0, type: DATA, size: 64512 Mar 30 18:59:20 moonlight vtltape[8446]: rewind_tape(): Media is writable Mar 30 18:59:20 moonlight vtltape[8446]: completeSCSICommand(): OP s/n: (217), sz: 0, sam_status: 0 Mar 30 18:59:20 moonlight vtltape[8446]: CDB (218) (delay 405): 08 00 00 fc 00 00 Mar 30 18:59:20 moonlight vtltape[8446]: ssc_read_6(): READ_6 (218) : 64512 bytes ** Mar 30 18:59:20 moonlight kernel: vtltape[8446]: segfault at 626280 ip 0000000000626280 sp 00007fff50b64b88 error 15 in vtltape[621000+6000] And here is the error from bacula: 30-Mar 18:57 bacula-dir JobId 79: Start Backup JobId 79, Job=mail-backup.2013-03-30_18.57.12_07 30-Mar 18:57 bacula-dir JobId 79: Using Device "Ultrium3" 30-Mar 18:57 bacula-sd JobId 79: 3301 Issuing autochanger "loaded? drive 0" command. 30-Mar 18:57 bacula-sd JobId 79: 3302 Autochanger "loaded? drive 0", result: nothing loaded. 30-Mar 18:57 bacula-sd JobId 79: 3304 Issuing autochanger "load slot 3, drive 0" command. 30-Mar 18:57 bacula-sd JobId 79: 3305 Autochanger "load slot 3, drive 0", status is OK. 30-Mar 18:57 bacula-sd JobId 79: Error: block.c:277 Volume data error at 0:0! Wanted ID: "BB02", got "UUUU". Buffer discarded. 30-Mar 18:57 b3 JobId 79: Fatal error: job.c:2001 Comm error with SD. bad response to Append Data. ERR=No data available 30-Mar 18:58 bacula-dir JobId 79: Error: Bacula bacula-dir 5.0.0 (26Jan10): 30-Mar-2013 18:58:10 Hope this gives some clues? And, before I forget, happy Easter ;-) Kind regards, Albert Pauw |
Re: vtltape segfault with gitversion including commit from March 28
|
Administrator
|
Happy Easter.. Any chance for a 'gdb /usr/bin/vtltape /path/to/core' gdb> bt gdb> quit Also a copy of device.conf I'll look at this on Tuesday. Cheers Sent from my iPad On Mar 31, 2013, at 5:04, "ap2010 [via MHVTL - Linux Virtual Tape Library - Community Forums]" <[hidden email]> wrote:
Regards from Australia
Mark Harvey |
|
|
Hi Mark,
I had loads of problems trying to locate the core dump file, which was nowhere to be found. In the end, as a last resort I did a make clean on the git source, recompile and install, and did the same for the kernel module (make clean; make; make install) and it works again nw. I assume that the kernel module (which was installed) didn't match the latest vtltape binary for some reason. So, note to myself, whenever weird things happen with mhvtl, recompile and install from scratch, including the kernel module. Kind regards, Albert On 03/31/2013 01:30 AM, Mark Harvey [via MHVTL - Linux Virtual Tape Library - Community Forums] wrote:
|
Re: vtltape segfault with gitversion including commit from March 28
|
Administrator
|
I can't see where any of the kernel module changes would have brought this unstuck..
However, the vtlcart.so & vtlscsi.so changes may have. Re: core file. Did you check the 'ulimit -c' value. Most Linux distributions default to '0' or no core file. A 'ulimit -c unlimited' before starting any daemons (from the same shell) is normally required. The main thing is that the problem has gone away :)
Regards from Australia
Mark Harvey |
|
|
Hi Mark, I checked the ulimit which was unlimited, just for fun I will try the explicit ulimit -c unlimited tonight to see if that works.Albert On 2 April 2013 03:48, Mark Harvey [via mhVTL - Linux Virtual Tape Library - Community Forums] <[hidden email]> wrote: I can't see where any of the kernel module changes would have brought this unstuck.. |
«
Return to mhVTL - A Linux Virtual Tape Library
|
1 view|%1 views
| Free forum by Nabble | Edit this page |