From owner-freebsd-scsi@FreeBSD.ORG Mon Jun 25 19:31:43 2012 Return-Path: Delivered-To: freebsd-scsi@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id D6C56106566C; Mon, 25 Jun 2012 19:31:43 +0000 (UTC) (envelope-from holm@beast.freibergnet.de) Received: from bmail.freibergnet.de (bmail.freibergnet.de [46.4.195.14]) by mx1.freebsd.org (Postfix) with ESMTP id CF4578FC14; Mon, 25 Jun 2012 19:31:42 +0000 (UTC) Received: from bmail.freibergnet.de (bmail.freibergnet.de [46.4.195.14]) by bmail.freibergnet.de (Postfix) with ESMTP id 99A4A929A50B; Mon, 25 Jun 2012 21:31:41 +0200 (CEST) X-Virus-Scanned: amavisd-new at freibergnet.de Received: from bmail.freibergnet.de ([46.4.195.14]) by bmail.freibergnet.de (bmail.freibergnet.de [46.4.195.14]) (amavisd-new, port 10024) with LMTP id 3GdXV8WoQwSz; Mon, 25 Jun 2012 21:31:38 +0200 (CEST) Received: from beast.freibergnet.de (bmail.freibergnet.de [46.4.195.14]) by bmail.freibergnet.de (Postfix) with ESMTP id CC8C2929A500; Mon, 25 Jun 2012 21:31:38 +0200 (CEST) Received: by beast.freibergnet.de (Postfix, from userid 201) id C77A84B791B; Mon, 25 Jun 2012 21:31:38 +0200 (CEST) Date: Mon, 25 Jun 2012 21:31:38 +0200 From: Holm Tiffe To: "Kenneth D. Merry" Message-ID: <20120625193138.GB82032@beast.freibergnet.de> Mail-Followup-To: Holm Tiffe , "Kenneth D. Merry" , freebsd-scsi@freebsd.org References: <20120601124338.GU2358@deviant.kiev.zoral.com.ua> <20120601125824.GV2358@deviant.kiev.zoral.com.ua> <20120606170640.GA98428@nargothrond.kdm.org> <20120625135543.GA58915@beast.freibergnet.de> <20120625155316.GA37535@nargothrond.kdm.org> Mime-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: <20120625155316.GA37535@nargothrond.kdm.org> User-Agent: Mutt/1.4.2.3i Organization: FreibergNet Internet Services, TSHT Priority: normal X-Phone: +49-3731-74222 X-Mobile: +49-172-8790741 X-Fax: +49-3731-74200 Cc: freebsd-scsi@freebsd.org Subject: Re: Kernel panic in FreeBSD-8.3 from UFS X-BeenThere: freebsd-scsi@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: holm@freibergnet.de List-Id: SCSI subsystem List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 25 Jun 2012 19:31:44 -0000 Kenneth D. Merry wrote: > On Mon, Jun 25, 2012 at 15:55:43 +0200, Holm Tiffe wrote: > > Kenneth D. Merry wrote: > > > > > On Tue, Jun 05, 2012 at 17:49:05 +0530, Desai, Kashyap wrote: > > > > Hi All, > > > > > > > > We found some potential area of memory leak in CAM layer. > > > > CAM XPT Memory leak is due to following function in scsi/scsi_all.c > > > > > > > > int > > > > scsi_command_string(struct ccb_scsiio *csio, struct sbuf *sb) > > > > > > > > > > > > In above function, CAM layer allocate memory for ccb device as below > > > > if ((cgd = (struct ccb_getdev*)xpt_alloc_ccb_nowait()) == NULL) > > > > > > > > > > > > _But_, unfortunately we never free the allocated memory and we see memory leak of 2K every time when someone is calling > > > > Scsi_command_string from kernel mode. > > > > > > > > > > > > Attached is a proposed patch for this issue. > > > > > > The patch looks good, I just committed it. > > > > > > Thanks! > > > > > > Ken > > > -- > > > Kenneth Merry > > > ken@FreeBSD.ORG > > > _______________________________________________ > > > freebsd-scsi@freebsd.org mailing list > > > http://lists.freebsd.org/mailman/listinfo/freebsd-scsi > > > To unsubscribe, send any mail to "freebsd-scsi-unsubscribe@freebsd.org" > > > > > > It looks that this patch or something related to it broke my tape backups. > > I do have two SCSI Tapes connected to my system: > > > > # camcontrol devlist > > at scbus0 target 0 lun 0 (pass0,da0) > > at scbus0 target 1 lun 0 (pass1,da1) > > at scbus0 target 2 lun 0 (pass2,da2) > > at scbus0 target 3 lun 0 (pass3,da3) > > at scbus1 target 5 lun 0 (pass4,sa0) > > at scbus1 target 6 lun 0 (pass5,sa1) > > > > an with an 8.3 stable from Jun 14 both of them arent able anymore to do > > blocksizes over 8k and 8k are only working sometimes (huh?!). > > The change in the above email didn't get merged back to stable/8 until June > 20th. So it isn't that. > > There were no changes to the sa(4) driver in stable/8 from March 15th to > June 14th, but there were lots of other CAM changes. > > > # mt -f /dev/sa1 status > > Mode Density Blocksize bpi Compression > > Current: 0x1a:DLTapeIV(20GB) variable 81633 IDRC > > ---------available modes--------- > > 0: 0x1a:DLTapeIV(20GB) variable 81633 IDRC > > 1: 0x1a:DLTapeIV(20GB) variable 81633 IDRC > > 2: 0x1a:DLTapeIV(20GB) variable 81633 IDRC > > 3: 0x1a:DLTapeIV(20GB) variable 81633 IDRC > > --------------------------------- > > Current Driver State: at rest. > > --------------------------------- > > File Number: 0 Record Number: 0 Residual Count 0 > > > > # dd if=/dev/zero of=/dev/sa1 bs=1k count=1000 > > 1000+0 records in > > 1000+0 records out > > 1024000 bytes transferred in 4.330778 secs (236447 bytes/sec) > > # dd if=/dev/zero of=/dev/sa1 bs=2k count=1000 > > 1000+0 records in > > 1000+0 records out > > 2048000 bytes transferred in 3.252421 secs (629685 bytes/sec) > > # dd if=/dev/zero of=/dev/sa1 bs=4k count=1000 > > 1000+0 records in > > 1000+0 records out > > 4096000 bytes transferred in 2.933208 secs (1396423 bytes/sec) > > # dd if=/dev/zero of=/dev/sa1 bs=8k count=1000 > > 1000+0 records in > > 1000+0 records out > > 8192000 bytes transferred in 3.567864 secs (2296052 bytes/sec) > > # dd if=/dev/zero of=/dev/sa1 bs=16k count=1000 > > dd: /dev/sa1: Input/output error > > 1+0 records in > > 0+0 records out > > 0 bytes transferred in 0.000253 secs (0 bytes/sec) > > > > There is no error message from the kernel related to that. > > > > If I try to read an older backup tape (used 64k Tape Blocks for that): > > # dd if=/dev/sa1 of=/dev/null bs=64k count=10 > > dd: /dev/sa1: Input/output error > > 0+0 records in > > 0+0 records out > > 0 bytes transferred in 0.000824 secs (0 bytes/sec) > > # > > ... I get in /var/log/messages: > > > > Jun 25 14:56:05 unicorn kernel: (sa1:sym0:0:6:0): 65536-byte tape record > > bigger than supplied buffer > > > > Nice ehy? > > > > I've now booted kernel.old from Mar 15 and the problems are gone on both > > drives. > > It isn't obvious where the problem was introduced, unfortunately. > > Could you do a binary search to figure out which revision broke things for > you? > > Ken > -- > Kenneth Merry > ken@FreeBSD.ORG Sorry, I (really) don't have the time to do that. But I've cvsupped and built a world and a kernel from today, the result is, that the error is gone, but the performance is somewhere below the basement: 0: 0x1a:DLTapeIV(20GB) variable 81633 IDRC 1: 0x1a:DLTapeIV(20GB) variable 81633 IDRC 2: 0x1a:DLTapeIV(20GB) variable 81633 IDRC 3: 0x1a:DLTapeIV(20GB) variable 81633 IDRC --------------------------------- Current Driver State: at rest. --------------------------------- File Number: 0 Record Number: 0 Residual Count 0 # dd if=/dev/zero of=/dev/sa1 bs=64k count=10000 10000+0 records in 10000+0 records out 655360000 bytes transferred in 125.909593 secs (5205005 bytes/sec) # It think the DLT drive should be streaming while writing 64K Blocks from /dev/zero, shouldn't it? No, it moves back and forward all the time. :-| This is only the first half of the truth, here is the 2nd: # dd of=/dev/null if=/dev/sa1 bs=64k 10000+0 records in 10000+0 records out 655360000 bytes transferred in 211.903853 secs (3092723 bytes/sec) # # # dd of=/dev/null if=/dev/sa1 bs=64k 10000+0 records in 10000+0 records out 655360000 bytes transferred in 211.942410 secs (3092161 bytes/sec) # This thing is reading even slower than writing, the Drive makes pauses of almost 10 seconds between the really short runs. The system is idle. Please Guys, Im running -Stable and I'm doing this since I really don't like such kind of features. Could I please get back a stable system with the ability to backup my data? Regards, Holm $ vmstat -i interrupt total rate irq0: clk 2768221 1000 irq1: atkbd0 13413 4 irq3: uart1 79 0 irq5: pcm0 rl0+ 977 0 irq6: fdc0 20 0 irq7: ppc0 1 0 irq8: rtc 2811413 1015 irq11: ahd0 ehci0 15654 5 irq12: psm0 27228 9 irq15: de0 sym0+++* 52176 18 Total 5689182 2055 $ # camcontrol devlist at scbus0 target 0 lun 0 (pass0,da0) at scbus0 target 1 lun 0 (pass1,da1) at scbus0 target 2 lun 0 (pass2,da2) at scbus0 target 3 lun 0 (pass3,da3) at scbus1 target 5 lun 0 (sa0,pass4) at scbus1 target 6 lun 0 (sa1,pass5) # uname -a FreeBSD unicorn.tsht.lan 8.3-STABLE FreeBSD 8.3-STABLE #24: Mon Jun 25 20:00:51 CEST 2012 holm@unicorn.tsht.lan:/data/FreeBSD/obj/data/FreeBSD/src/sys/UNICORN i386 # Copyright (c) 1992-2012 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights reserved. FreeBSD is a registered trademark of The FreeBSD Foundation. FreeBSD 8.3-STABLE #24: Mon Jun 25 20:00:51 CEST 2012 holm@unicorn.tsht.lan:/data/FreeBSD/obj/data/FreeBSD/src/sys/UNICORN i386 Timecounter "i8254" frequency 1193182 Hz quality 0 CPU: AMD Athlon(tm) XP 3000+ (2109.49-MHz 686-class CPU) Origin = "AuthenticAMD" Id = 0x6a0 Family = 6 Model = a Stepping = 0 Features=0x383fbff AMD Features=0xc0400800 real memory = 2147483648 (2048 MB) avail memory = 2092101632 (1995 MB) kbd1 at kbdmux0 acpi0: on motherboard acpi0: [ITHREAD] acpi0: Power Button (fixed) acpi0: reservation of 0, a0000 (3) failed acpi0: reservation of 100000, 7fef0000 (3) failed cpu0: on acpi0 acpi_button0: on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 agp0: on hostb0 agp0: aperture size is 128M pcib1: at device 1.0 on pci0 pci1: on pcib1 vgapci0: port 0xa000-0xa0ff mem 0xd8000000-0xdfffffff,0xe9000000-0xe900ffff irq 15 at device 0.0 on pci1 drm0: on vgapci0 info: [drm] AGP at 0xd0000000 128MB info: [drm] Initialized radeon 1.31.0 20080613 vgapci1: mem 0xe0000000-0xe7ffffff,0xe9010000-0xe901ffff at device 0.1 on pci1 de0: port 0xb000-0xb07f mem 0xeb002000-0xeb00207f irq 15 at device 9.0 on pci0 de0: Cogent 21040 [10Mb/s] pass 2.3 de0: WARNING: using obsoleted if_watchdog interface de0: Ethernet address: 00:00:92:90:09:8d de0: [ITHREAD] ahd0: port 0xb400-0xb4ff,0xb800-0xb8ff mem 0xeb000000-0xeb001fff irq 11 at device 11.0 on pci0 ahd0: [ITHREAD] aic7901A: Ultra320 Wide Channel A, SCSI Id=7, PCI 33 or 66MHz, 512 SCBs puc0: port 0xbc00-0xbc07,0xc000-0xc007,0xc400-0xc41f mem 0xeb003000-0xeb003fff,0xeb004000-0xeb004fff irq 15 at device 12.0 on pci0 puc0: [FILTER] uart2: <16550 or compatible> at port 1 on puc0 uart2: [FILTER] uart3: <16550 or compatible> at port 2 on puc0 uart3: [FILTER] sym0: <810a> port 0xc800-0xc8ff mem 0xeb005000-0xeb0050ff irq 15 at device 13.0 on pci0 sym0: No NVRAM, ID 7, Fast-10, SE, parity checking sym0: [ITHREAD] uhci0: port 0xcc00-0xcc1f irq 15 at device 16.0 on pci0 uhci0: [ITHREAD] usbus0 on uhci0 uhci1: port 0xd000-0xd01f irq 15 at device 16.1 on pci0 uhci1: [ITHREAD] usbus1 on uhci1 uhci2: port 0xd400-0xd41f irq 5 at device 16.2 on pci0 uhci2: [ITHREAD] usbus2 on uhci2 ehci0: mem 0xeb006000-0xeb0060ff irq 11 at device 16.3 on pci0 ehci0: [ITHREAD] usbus3: EHCI version 1.0 usbus3 on ehci0 isab0: at device 17.0 on pci0 isa0: on isab0 atapci0: port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xd800-0xd80f at device 17.1 on pci0 ata0: at channel 0 on atapci0 ata0: [ITHREAD] ata1: at channel 1 on atapci0 ata1: [ITHREAD] pcm0: port 0xdc00-0xdcff irq 5 at device 17.5 on pci0 pcm0: [ITHREAD] pcm0: pcm0: rl0: port 0xe000-0xe0ff mem 0xeb007000-0xeb0070ff irq 5 at device 19.0 on pci0 miibus0: on rl0 rlphy0: PHY 0 on miibus0 rlphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto rl0: Ethernet address: 00:0d:61:c3:c4:5a rl0: [ITHREAD] atrtc0: port 0x70-0x73 irq 8 on acpi0 fdc0: port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0 fdc0: [FILTER] fd0: <1440-KB 3.5" drive> on fdc0 drive 0 fd1: <1200-KB 5.25" drive> on fdc0 drive 1 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart0: [FILTER] uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0 uart1: [FILTER] ppc0: port 0x378-0x37f,0x778-0x77b irq 7 drq 3 on acpi0 ppc0: SMC-like chipset (ECP/EPP/PS2/NIBBLE) in COMPATIBLE mode ppc0: FIFO with 16/16/16 bytes threshold ppc0: [ITHREAD] ppbus0: on ppc0 plip0: on ppbus0 plip0: [ITHREAD] lpt0: on ppbus0 lpt0: [ITHREAD] lpt0: Interrupt-driven port ppi0: on ppbus0 atkbdc0: port 0x60,0x64 irq 1 on acpi0 atkbd0: irq 1 on atkbdc0 kbd0 at atkbd0 atkbd0: [GIANT-LOCKED] atkbd0: [ITHREAD] psm0: irq 12 on atkbdc0 psm0: [GIANT-LOCKED] psm0: [ITHREAD] psm0: model MouseMan+, device ID 0 pmtimer0 on isa0 orm0: at iomem 0xc0000-0xccfff,0xd0000-0xd97ff pnpid ORM0000 on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 Timecounter "TSC" frequency 2109485719 Hz quality 800 Timecounters tick every 1.000 msec usbus0: 12Mbps Full Speed USB v1.0 usbus1: 12Mbps Full Speed USB v1.0 usbus2: 12Mbps Full Speed USB v1.0 usbus3: 480Mbps High Speed USB v2.0 ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 ugen2.1: at usbus2 uhub2: on usbus2 ugen3.1: at usbus3 uhub3: on usbus3 uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered uhub2: 2 ports with 2 removable, self powered uhub3: 6 ports with 6 removable, self powered (probe20:sym0:0:5:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 (probe20:sym0:0:5:0): CAM status: SCSI Status Error (probe20:sym0:0:5:0): SCSI status: Check Condition (probe20:sym0:0:5:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred) (probe21:sym0:0:6:0): TEST UNIT READY. CDB: 0 0 0 0 0 0 (probe21:sym0:0:6:0): CAM status: SCSI Status Error (probe21:sym0:0:6:0): SCSI status: Check Condition (probe21:sym0:0:6:0): SCSI sense: UNIT ATTENTION asc:29,0 (Power on, reset, or bus device reset occurred) da0 at ahd0 bus 0 scbus0 target 0 lun 0 da0: Fixed Direct Access SCSI-3 device da0: 160.000MB/s transfers (80.000MHz DT, offset 63, 16bit) da0: Command Queueing enabled da0: 70006MB (143374000 512 byte sectors: 255H 63S/T 8924C) da1 at ahd0 bus 0 scbus0 target 1 lun 0 da1: Fixed Direct Access SCSI-3 device da1: 160.000MB/s transfers (80.000MHz DT, offset 63, 16bit) da1: Command Queueing enabled da1: 70006MB (143374000 512 byte sectors: 255H 63S/T 8924C) da2 at ahd0 bus 0 scbus0 target 2 lun 0 da2: Fixed Direct Access SCSI-3 device da2: 160.000MB/s transfers (80.000MHz DT, offset 63, 16bit) da2: Command Queueing enabled da2: 70006MB (143374000 512 byte sectors: 255H 63S/T 8924C) da3 at ahd0 bus 0 scbus0 target 3 lun 0 da3: Fixed Direct Access SCSI-3 device da3: 160.000MB/s transfers (80.000MHz DT, offset 63, 16bit) da3: Command Queueing enabled da3: 70006MB (143374000 512 byte sectors: 255H 63S/T 8924C) sa0 at sym0 bus 0 scbus1 target 5 lun 0 sa0: Removable Sequential Access SCSI-2 device sa0: 4.166MB/s transfers (4.166MHz, offset 8) sa1 at sym0 bus 0 scbus1 target 6 lun 0 sa1: Removable Sequential Access SCSI-2 device sa1: 10.000MB/s transfers (10.000MHz, offset 8) GEOM_CONCAT: Device gc0d created (id=2065581164). GEOM_CONCAT: Disk da0d attached to gc0d. GEOM_CONCAT: Device data created (id=2038144655). GEOM_CONCAT: Disk da0g attached to data. GEOM_MIRROR: Device mirror/gm0a launched (2/2). GEOM_CONCAT: Disk da1d attached to gc0d. GEOM_CONCAT: Device gc0d activated. GEOM_MIRROR: Device mirror/gm0e launched (2/2). GEOM_MIRROR: Device mirror/gm0f launched (2/2). GEOM_CONCAT: Disk da1g attached to data. GEOM_CONCAT: Disk da2a attached to data. GEOM_CONCAT: Disk da2b attached to data. GEOM_CONCAT: Device data activated. Trying to mount root from ufs:/dev/mirror/gm0a bridge0: Ethernet address: 02:82:44:4d:6c:00 -- Technik Service u. Handel Tiffe, www.tsht.de, Holm Tiffe, Freiberger Straße 42, 09600 Oberschöna, USt-Id: DE253710583 www.tsht.de, info@tsht.de, Fax +49 3731 74200, Mobil: 0172 8790 741