From owner-freebsd-usb@FreeBSD.ORG Sun May 29 09:28:33 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id BB94616A41C for ; Sun, 29 May 2005 09:28:33 +0000 (GMT) (envelope-from sigsegv@radiotube.org) Received: from enterprise.localnet.radiotube.org (enterprise.radiotube.org [81.0.166.237]) by mx1.FreeBSD.org (Postfix) with ESMTP id 4DE7A43D1D for ; Sun, 29 May 2005 09:28:31 +0000 (GMT) (envelope-from sigsegv@radiotube.org) Received: from [10.53.4.10] ([10.53.4.10]) (authenticated bits=0) by enterprise.localnet.radiotube.org (8.13.1/8.13.1) with ESMTP id j4T9Rvpn049226 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Sun, 29 May 2005 11:28:20 +0200 (CEST) (envelope-from sigsegv@radiotube.org) Message-ID: <42998B18.8020806@radiotube.org> Date: Sun, 29 May 2005 11:27:52 +0200 From: Jan-Espen Pettersen User-Agent: Mozilla Thunderbird 1.0.2 (X11/20050329) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Ian Dowse References: <200505281627.aa05625@nowhere.iedowse.com> In-Reply-To: <200505281627.aa05625@nowhere.iedowse.com> X-Enigmail-Version: 0.91.0.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-usb@freebsd.org Subject: Re: ulpt_tick after close X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: sigsegv@radiotube.org List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 09:28:33 -0000 -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Ian Dowse wrote: |In message <4296EBFA.1070902@radiotube.org>, Jan-Espen Pettersen writes: | |>I've for a few weeks suspected that there was more problems with the USB |>printer implementation than those that have been resolved through |>usb/78208 (http://www.freebsd.org/cgi/query-pr.cgi?pr=78208). I found |>that ulpt_read_cb reschedules the ulpt_tick callout, but fails to check |>if sc->sc_has_callout is set. ulpt_close destroys the read xfer and |>unsets sc->sc_has_callout. Running ulpt_tick with the read xfer |>destroyed causes a page fault. Therefore I suggest checking |>sc->sc_has_callout in ulpt_read_cb before rescheduling the ulpt_tick |>callout. | | |Hi, | |It appears that ulptclose() should already be doing enough to |guarantee that neither ulpt_read_cb() nor ulpt_tick() get called |after it completes, so if the case you describe is happening then |it may suggest a deeper problem. What version of FreeBSD are you |using (branch + date)? Were there any "ulpt0: detached" or similar |messages just before or after your printf triggered? | No, there are no 'detached' messages. |The ulptclose() function first calls usb_uncallout(), which in |-CURRENT and RELENG_5 should guarantee that the ulpt_tick() will |not be called after ulptclose() completes. Next the sc_in_pipe is |aborted and closed. If there was an outstanding asynchronous request |in progress, then its callback (ulpt_read_cb) should be called |immediately with a status of USBD_CANCELLED, which will cause it |to skip rescheduling the callout. So once sc_in_pipe has been |aborted, neither the timeout nor the transfer should be active. | |What kind of USB printer do you have, and was there any special |kind of access that triggered the message? Once I know what version |of FreeBSD you're using I'll try to suggest some further things you |can do to narrow down the cause of the problem. | This is an Abit NF7-M board with Nforce-2 chipset. I am running without SMP and APIC, and with ACPI (partially working). By the way, everything else seem to be running quite fine: 11:23AM up 32 days, 4:14, 36 users, load averages: 0.10, 0.09, 0.06 ohci0: mem 0xef003000-0xef003fff irq 12 at device 2.0 on pci0 usb0: on ohci0 ohci1: mem 0xef004000-0xef004fff irq 5 at device 2.1 on pci0 usb1: on ohci1 ulpt0: Samsung Electronics Co., Ltd. Samsung ML-1710, rev 1.10/1.00, addr 4, iclass 7/1 ulpt0: using bi-directional mode http://www.linuxprinting.org/show_printer.cgi?recnum=Samsung-ML-1710 This happened immediately after sending a normal print job to the printer and before the printer was finished printing. FreeBSD endeavour.localnet.radiotube.org 5.4-STABLE FreeBSD 5.4-STABLE #0: Mon Apr 25 07:52:47 CEST 2005 sigsegv@endeavour.localnet.radiotube.org:/usr/obj/usr/src/FreeBSD-5/sys/ENDEAVOUR i386 I have: rev 1.65.2.1 of ulpt.c rev 1.86.2.4 of usbdi.c rev 1.144.2.4 of ohci.c I think I'll replace that printf with a panic in ulpt_read_cb to get a backtrace next time. (And at the same time update my sources) As it would reveal what is actually calling ulpt_read_cb after the callout has been stopped. The problem is that this is very unlikely to happen during a single print job, but it does over time, so it might take me some time to get that backtrace. -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.1 (FreeBSD) Comment: Using GnuPG with Thunderbird - http://enigmail.mozdev.org iD8DBQFCmYsYH90qNYni6VoRAjZKAKCI4VTbf2imK2pLNRiCVXRcgbZrqQCguNc0 O+Y+Bv9EHbK9u5RSw20fvmA= =8Xmy -----END PGP SIGNATURE----- From owner-freebsd-usb@FreeBSD.ORG Sun May 29 12:10:28 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 6191516A41C for ; Sun, 29 May 2005 12:10:28 +0000 (GMT) (envelope-from iedowse@iedowse.com) Received: from nowhere.iedowse.com (nowhere.iedowse.com [82.195.144.75]) by mx1.FreeBSD.org (Postfix) with SMTP id B964A43D1D for ; Sun, 29 May 2005 12:10:27 +0000 (GMT) (envelope-from iedowse@iedowse.com) Received: from localhost ([127.0.0.1] helo=iedowse.com) by nowhere.iedowse.com with SMTP id ; 29 May 2005 13:10:20 +0100 (IST) To: sigsegv@radiotube.org In-Reply-To: Your message of "Sun, 29 May 2005 11:27:52 +0200." <42998B18.8020806@radiotube.org> Date: Sun, 29 May 2005 13:10:19 +0100 From: Ian Dowse Message-ID: <200505291310.aa19689@nowhere.iedowse.com> Cc: Ian Dowse , freebsd-usb@freebsd.org Subject: Re: ulpt_tick after close X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 12:10:28 -0000 In message <42998B18.8020806@radiotube.org>, Jan-Espen Pettersen writes: >I think I'll replace that printf with a panic in ulpt_read_cb to get a >backtrace next time. (And at the same time update my sources) As it >would reveal what is actually calling ulpt_read_cb after the callout has >been stopped. The problem is that this is very unlikely to happen during >a single print job, but it does over time, so it might take me some time >to get that backtrace. Thanks for the details. By the way, is it lpd or something else that is actually accessing the ulpt device? Below is a patch you could try that will hopefully find out a bit more about what is going on. You could also change the new return statement in ulpt_read_cb() to a panic, as the stack trace might reveal more information like you say. Ian Index: ulpt.c =================================================================== RCS file: /dump/FreeBSD-CVS/src/sys/dev/usb/ulpt.c,v retrieving revision 1.65.2.1 diff -u -r1.65.2.1 ulpt.c --- ulpt.c 30 Jan 2005 01:00:10 -0000 1.65.2.1 +++ ulpt.c 29 May 2005 11:51:30 -0000 @@ -122,6 +122,7 @@ #define ULPT_OPEN 0x01 /* device is open */ #define ULPT_OBUSY 0x02 /* printer is busy doing output */ #define ULPT_INIT 0x04 /* waiting to initialize for open */ +#define ULPT_CLOSING 0x05 /* closing */ u_char sc_flags; #define ULPT_NOPRIME 0x40 /* don't prime on open */ u_char sc_laststatus; @@ -660,9 +661,13 @@ USB_GET_SC(ulpt, ULPTUNIT(dev), sc); - if (sc->sc_state != ULPT_OPEN) + if (sc->sc_state != ULPT_OPEN) { /* We are being forced to close before the open completed. */ + printf("%s: ignoring close in state %d\n", + USBDEVNAME(sc->sc_dev), sc->sc_state); return (0); + } + sc->sc_state = ULPT_CLOSING; if (sc->sc_has_callout) { usb_uncallout(sc->sc_read_callout, ulpt_tick, sc); @@ -810,6 +815,13 @@ usbd_get_xfer_status(xfer, &xsc, NULL, &n, &err); sc = xsc; + if (sc->sc_state != ULPT_OPEN && (status != USBD_CANCELLED || + err != USBD_CANCELLED)) { + printf("%s: ulpt_read_cb state=%d status=%s err=%s\n", + USBDEVNAME(sc->sc_dev), sc->sc_state, usbd_errstr(status), + usbd_errstr(err)); + return; + } DPRINTFN(1,("ulpt_read_cb: start sc=%p, err=%d n=%d\n", sc, err, n)); #ifdef ULPT_DEBUG @@ -832,6 +844,11 @@ DPRINTFN(1,("ulpt_tick: start sc=%p\n", sc)); + if (sc->sc_state != ULPT_OPEN) { + printf("%s: ulpt_tick state=%d\n", USBDEVNAME(sc->sc_dev), + sc->sc_state); + return; + } usbd_setup_xfer(sc->sc_in_xfer, sc->sc_in_pipe, sc, sc->sc_in_buf, ULPT_BSIZE, USBD_NO_COPY | USBD_SHORT_XFER_OK, ULPT_READ_TIMO, ulpt_read_cb); From owner-freebsd-usb@FreeBSD.ORG Sun May 29 13:30:03 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 014EA16A41C for ; Sun, 29 May 2005 13:30:03 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 99CF343D48 for ; Sun, 29 May 2005 13:30:02 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4TDU2hh042860 for ; Sun, 29 May 2005 13:30:02 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4TDU2eZ042857; Sun, 29 May 2005 13:30:02 GMT (envelope-from gnats) Resent-Date: Sun, 29 May 2005 13:30:02 GMT Resent-Message-Id: <200505291330.j4TDU2eZ042857@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-usb@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Gerrit Kühn Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 6BB2116A41C for ; Sun, 29 May 2005 13:26:36 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (www.freebsd.org [216.136.204.117]) by mx1.FreeBSD.org (Postfix) with ESMTP id 2E6C943D1F for ; Sun, 29 May 2005 13:26:36 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.13.1/8.13.1) with ESMTP id j4TDQZWF084811 for ; Sun, 29 May 2005 13:26:35 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.13.1/8.13.1/Submit) id j4TDQYCh084810; Sun, 29 May 2005 13:26:34 GMT (envelope-from nobody) Message-Id: <200505291326.j4TDQYCh084810@www.freebsd.org> Date: Sun, 29 May 2005 13:26:34 GMT From: Gerrit Kühn To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-2.3 Cc: Subject: usb/81621: external hd hangs under load on ehci X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 13:30:03 -0000 >Number: 81621 >Category: usb >Synopsis: external hd hangs under load on ehci >Confidential: no >Severity: non-critical >Priority: low >Responsible: freebsd-usb >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Sun May 29 13:30:02 GMT 2005 >Closed-Date: >Last-Modified: >Originator: Gerrit Kühn >Release: 5-stable >Organization: Universität Hannover >Environment: root@stardust.terra.ger:/usr/obj/usr/src/sys/STARDUST iFreeBSD stardust.terra.ger 5.4-STABLE FreeBSD 5.4-STABLE #25: Sat May 7 22:22:04 CEST 2005 root@stardust.terra.ger:/usr/obj/usr/src/sys/STARDUST i386 386 >Description: I'm using a Vosoniq XS-DrivePro VP-300, which is basically an external 2.5"HD combined with a cardreader. The device works perfectly with 500-600kB/s when connected to the internal USB1 port of the mainboard (VIA chipset), and basically works with ~2MB/s on a USB2 port of a DLink DU-520 card (NEC chipset). However, after transferring some data via USB2/EHCI (usually some 10MB), the connection locks up and waits for some kind of timeout (several minutes). After that, transfer is resumed until the next lockup occurs. uhci0@pci0:7:2: class=0x0c0300 card=0x12340925 chip=0x30381106 rev=0x16 hdr=0x00 vendor = 'VIA Technologies Inc' device = 'VT82xxxxx UHCI USB 1.1 Controller (All VIA Chipsets)' class = serial bus subclass = USB uhci1@pci0:7:3: class=0x0c0300 card=0x12340925 chip=0x30381106 rev=0x16 hdr=0x00 vendor = 'VIA Technologies Inc' device = 'VT82xxxxx UHCI USB 1.1 Controller (All VIA Chipsets)' class = serial bus subclass = USB ohci0@pci0:14:0: class=0x0c0310 card=0x00351186 chip=0x00351033 rev=0x43 hdr=0x00 vendor = 'NEC Electronics Hong Kong' device = 'uPD9210FGC-7EA / µPD720101 USB 1.0 Host Controller (OHCI compliant)' class = serial bus subclass = USB ohci1@pci0:14:1: class=0x0c0310 card=0x00351186 chip=0x00351033 rev=0x43 hdr=0x00 vendor = 'NEC Electronics Hong Kong' device = 'uPD9210FGC-7EA / µPD720101 USB 1.0 Host Controller (OHCI compliant)' class = serial bus subclass = USB ehci0@pci0:14:2: class=0x0c0320 card=0xf1011186 chip=0x00e01033 rev=0x04 hdr=0x00 vendor = 'NEC Electronics Hong Kong' device = 'uPD720100A/101 USB 2.0 Enhanced Host Controller' class = serial bus subclass = USB Please let me know if I can provide further information to solve this problem. >How-To-Repeat: Just use the XS-Drive with USB2 and transfer an sufficient amount of data. >Fix: >Release-Note: >Audit-Trail: >Unformatted: From owner-freebsd-usb@FreeBSD.ORG Sun May 29 15:20:05 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 140EE16A41C for ; Sun, 29 May 2005 15:20:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id CD6CA43D49 for ; Sun, 29 May 2005 15:20:04 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4TFK4c5056110 for ; Sun, 29 May 2005 15:20:04 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4TFK4YU056109; Sun, 29 May 2005 15:20:04 GMT (envelope-from gnats) Date: Sun, 29 May 2005 15:20:04 GMT Message-Id: <200505291520.j4TFK4YU056109@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Dominic Marks Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Dominic Marks List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 15:20:05 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: Dominic Marks To: Bruce Evans Cc: freebsd-gnats-submit@FreeBSD.org, banhalmi@field.hu, freebsd-fs@FreeBSD.org Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Sun, 29 May 2005 16:12:46 +0100 --Boundary-00=_uvdmCBeoNTBAj+g Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline On Saturday 28 May 2005 15:40, Dominic Marks wrote: > On Saturday 28 May 2005 12:13, Dominic Marks wrote: > > On Saturday 28 May 2005 11:36, Bruce Evans wrote: > > > > > > I use the following to improve transfer rates for msdosfs. The patch > > > is for an old version so it might not apply directly. > > > > > Thanks! I'll try my three tests again with this patch. > > Index: msdosfs_vnops.c > =================================================================== > RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > retrieving revision 1.149.2.1 > diff -u -r1.149.2.1 msdosfs_vnops.c > --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 > +++ msdosfs_vnops.c 28 May 2005 14:26:59 -0000 > @@ -607,6 +607,7 @@ > struct uio *a_uio; > int a_ioflag; > struct ucred *a_cred; > + int seqcount; > } */ *ap; > { > int n; > @@ -615,6 +616,7 @@ > u_long osize; > int error = 0; > u_long count; > + int seqcount; > daddr_t bn, lastcn; > struct buf *bp; > int ioflag = ap->a_ioflag; > @@ -692,7 +694,7 @@ > */ > if (uio->uio_offset + resid > osize) { > count = de_clcount(pmp, uio->uio_offset + resid) - > - de_clcount(pmp, osize); > + de_clcount(pmp, osize); > error = extendfile(dep, count, NULL, NULL, 0); > if (error && (error != ENOSPC || (ioflag & IO_UNIT))) > goto errexit; > @@ -700,6 +702,7 @@ > } else > lastcn = de_clcount(pmp, osize) - 1; > > + seqcount = ioflag >> IO_SEQSHIFT; > do { > if (de_cluster(pmp, uio->uio_offset) > lastcn) { > error = ENOSPC; > @@ -725,7 +728,7 @@ > * then no need to read data from disk. > */ > bp = getblk(thisvp, bn, pmp->pm_bpcluster, 0, 0, 0); > - clrbuf(bp); > + vfs_bio_clrbuf(bp); > /* > * Do the bmap now, since pcbmap needs buffers > * for the fat table. (see msdosfs_strategy) > @@ -775,6 +778,7 @@ > * without delay. Otherwise do a delayed write because we > * may want to write somemore into the block later. > */ > + /* > if (ioflag & IO_SYNC) > (void) bwrite(bp); > else if (n + croffset == pmp->pm_bpcluster) > @@ -782,6 +786,24 @@ > else > bdwrite(bp); > dep->de_flag |= DE_UPDATE; > + */ > + /* > + * XXX Patch. > + */ > + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) > + bp->b_flags |= B_CLUSTEROK; > + if (ioflag & IO_SYNC) > + (void)bwrite(bp); > + else if (vm_page_count_severe() || > buf_dirty_count_severe()) + bawrite(bp); > + else if (n + croffset == pmp->pm_bpcluster) { > + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) > + cluster_write(bp, dep->de_FileSize, > seqcount); + else > + bawrite(bp); > + } else > + bdwrite(bp); > + dep->de_flag |= DE_UPDATE; > } while (error == 0 && uio->uio_resid > 0); > > /* > > Your patch works for me on 5.4-STABLE. It improves write performance > dramatically. I did another test, reading and writing 1GB chunks of data. > Since the patch is to the _write function is it safe to assume the same > method could be used to fix read performance if applied properly in the > correct function? > > Cheers, I have been experimenting in msdosfs_read and I have managed to come up with something that works, but I'm sure it is flawed. On large file reads it will improve read performance (see below) - but only after a long period of the file copy achieving only 3MB/s (see A1). During this time gstat reports the disc itself is reading at its maximum of around 28MB/s. After a long period of low throughput, the disc drops to 25MB/s but the actual transfer rate increases to 25MB/s (see A2). I've tried to narrow it down to something but I'm mostly in the dark, so I'll just hand over what I found to work to review. I looked at Bruce's changes to msdosfs_write and tried to do the same (implement cluster_read) using the ext2 and ffs _read methods as a how-to. I think I'm reading ahead too far, or too early. I have been unable to interpret the gstat output during the first part of the transfer any further. gstat(8) output at the start (slow, A1), and middle (fast, A2) of a large file copy between msdosfs/usb drive (da0s1) and ufs2/ata-100 (ad1). # A1 dT: 0.501 flag_I 500000us sizeof 240 i -1 L(q) ops/s r/s kBps ms/r w/s kBps ms/w %busy Name 14 445 445 28376 24.7 0 0 0.0 99.9| da0 0 28 0 0 0.0 28 3578 1.7 4.8| ad1 0 28 0 0 0.0 28 3578 1.7 4.8| ad1s1 14 445 445 28376 24.9 0 0 0.0 100.0| da0s1 After 30-45 seconds (1GB test file): # A2 dT: 0.501 flag_I 500000us sizeof 240 i -1 L(q) ops/s r/s kBps ms/r w/s kBps ms/w %busy Name 1 403 403 25428 2.1 0 0 0.0 85.0| da0 0 199 0 0 0.0 199 25532 1.7 34.0| ad1 0 199 0 0 0.0 199 25532 1.7 34.1| ad1s1 1 403 403 25428 2.1 0 0 0.0 85.9| da0s1 The patch which combines Bruce's original patch for msdosfs_write, revised for current text positions, and my attempts to do the same for msdosfs_read. %% Index: msdosfs_vnops.c =================================================================== RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v retrieving revision 1.149.2.1 diff -u -r1.149.2.1 msdosfs_vnops.c --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 @@ -517,6 +517,8 @@ int blsize; int isadir; int orig_resid; + int nblks = 16; /* XXX should be defined, but not here */ + int crsize; u_int n; u_long diff; u_long on; @@ -565,14 +567,21 @@ error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); } else { blsize = pmp->pm_bpcluster; - rablock = lbn + 1; - if (seqcount > 1 && - de_cn2off(pmp, rablock) < dep->de_FileSize) { - rasize = pmp->pm_bpcluster; - error = breadn(vp, lbn, blsize, - &rablock, &rasize, 1, NOCRED, &bp); + /* XXX what is the best value for crsize? */ + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : blsize * nblks; + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { + error = cluster_read(vp, dep->de_FileSize, lbn, + crsize, NOCRED, uio->uio_resid, seqcount, &bp); } else { - error = bread(vp, lbn, blsize, NOCRED, &bp); + rablock = lbn + 1; + if (seqcount > 1 && + de_cn2off(pmp, rablock) < dep->de_FileSize) { + rasize = pmp->pm_bpcluster; + error = breadn(vp, lbn, blsize, + &rablock, &rasize, 1, NOCRED, &bp); + } else { + error = bread(vp, lbn, blsize, NOCRED, &bp); + } } } if (error) { @@ -580,14 +589,16 @@ break; } on = uio->uio_offset & pmp->pm_crbomask; - diff = pmp->pm_bpcluster - on; - n = diff > uio->uio_resid ? uio->uio_resid : diff; + diff = blsize * nblks - on; + n = blsize * nblks > uio->uio_resid ? uio->uio_resid : blsize * nblks; diff = dep->de_FileSize - uio->uio_offset; - if (diff < n) + if (diff < n) { n = diff; - diff = blsize - bp->b_resid; - if (diff < n) + } + diff = blsize * nblks - bp->b_resid; + if (diff < n) { n = diff; + } error = uiomove(bp->b_data + on, (int) n, uio); brelse(bp); } while (error == 0 && uio->uio_resid > 0 && n != 0); @@ -607,6 +618,7 @@ struct uio *a_uio; int a_ioflag; struct ucred *a_cred; + int seqcount; } */ *ap; { int n; @@ -615,6 +627,7 @@ u_long osize; int error = 0; u_long count; + int seqcount; daddr_t bn, lastcn; struct buf *bp; int ioflag = ap->a_ioflag; @@ -692,7 +705,7 @@ */ if (uio->uio_offset + resid > osize) { count = de_clcount(pmp, uio->uio_offset + resid) - - de_clcount(pmp, osize); + de_clcount(pmp, osize); error = extendfile(dep, count, NULL, NULL, 0); if (error && (error != ENOSPC || (ioflag & IO_UNIT))) goto errexit; @@ -700,6 +713,7 @@ } else lastcn = de_clcount(pmp, osize) - 1; + seqcount = ioflag >> IO_SEQSHIFT; do { if (de_cluster(pmp, uio->uio_offset) > lastcn) { error = ENOSPC; @@ -725,7 +739,7 @@ * then no need to read data from disk. */ bp = getblk(thisvp, bn, pmp->pm_bpcluster, 0, 0, 0); - clrbuf(bp); + vfs_bio_clrbuf(bp); /* * Do the bmap now, since pcbmap needs buffers * for the fat table. (see msdosfs_strategy) @@ -775,6 +789,7 @@ * without delay. Otherwise do a delayed write because we * may want to write somemore into the block later. */ + /* if (ioflag & IO_SYNC) (void) bwrite(bp); else if (n + croffset == pmp->pm_bpcluster) @@ -782,6 +797,24 @@ else bdwrite(bp); dep->de_flag |= DE_UPDATE; + */ + /* + * XXX Patch. + */ + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + bp->b_flags |= B_CLUSTEROK; + if (ioflag & IO_SYNC) + (void)bwrite(bp); + else if (vm_page_count_severe() || buf_dirty_count_severe()) + bawrite(bp); + else if (n + croffset == pmp->pm_bpcluster) { + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + cluster_write(bp, dep->de_FileSize, seqcount); + else + bawrite(bp); + } else + bdwrite(bp); + dep->de_flag |= DE_UPDATE; } while (error == 0 && uio->uio_resid > 0); /* %% With this patch I can get the following transfer rates: msdosfs reading # ls -lh /mnt/random2.file -rwxr-xr-x 1 root wheel 1.0G May 29 11:24 /mnt/random2.file # /usr/bin/time -al cp /mnt/random2.file /vol 59.61 real 0.05 user 6.79 sys 632 maximum resident set size 11 average shared memory size 80 average unshared data size 123 average unshared stack size 88 page reclaims 0 page faults 0 swaps 23757 block input operations ** 8192 block output operations 0 messages sent 0 messages received 0 signals received 16660 voluntary context switches 10387 involuntary context switches Average Rate: 15.31MB/s. (Would be higher if not for the slow start) ** This figure is 3x that of the UFS2 operations. This must be a indicator of what I'm doing wrong, but I don't know what. msdosfs writing # /usr/bin/time -al cp /vol/random2.file /mnt 47.33 real 0.03 user 7.13 sys 632 maximum resident set size 12 average shared memory size 85 average unshared data size 130 average unshared stack size 88 page reclaims 0 page faults 0 swaps 8735 block input operations 16385 block output operations 0 messages sent 0 messages received 0 signals received 8856 voluntary context switches 29631 involuntary context switches Average Rate: 18.79MB/s. To compare with UFS2 + softupdates on the same system / disc. ufs2 reading # /usr/bin/time -al cp /mnt/random2.file /vol 42.39 real 0.02 user 6.61 sys 632 maximum resident set size 12 average shared memory size 87 average unshared data size 133 average unshared stack size 88 page reclaims 0 page faults 0 swaps 8249 block input operations 8193 block output operations 0 messages sent 0 messages received 0 signals received 8246 voluntary context switches 24617 involuntary context switches Average Rate: 20.89MB/s. ufs2 writing # /usr/bin/time -al cp /vol/random2.file /mnt/ 47.12 real 0.03 user 6.74 sys 632 maximum resident set size 12 average shared memory size 85 average unshared data size 130 average unshared stack size 88 page reclaims 0 page faults 0 swaps 8260 block input operations 8192 block output operations 0 messages sent 0 messages received 0 signals received 8303 voluntary context switches 24700 involuntary context switches Average Rate: 19MB/s. I'd hope that someone could point me in the right direction so I can clean the patch up, or finish this off themselves and commit it (or something else which will increase the read/write speed). Thanks very much, -- Dominic GoodforBusiness.co.uk I.T. Services for SMEs in the UK. --Boundary-00=_uvdmCBeoNTBAj+g Content-Type: text/x-diff; charset="iso-8859-1"; name="msdos-perf-releng5.patch" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="msdos-perf-releng5.patch" Index: msdosfs_vnops.c =================================================================== RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v retrieving revision 1.149.2.1 diff -u -r1.149.2.1 msdosfs_vnops.c --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 @@ -517,6 +517,8 @@ int blsize; int isadir; int orig_resid; + int nblks = 16; /* XXX should be defined, but not here */ + int crsize; u_int n; u_long diff; u_long on; @@ -565,14 +567,21 @@ error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); } else { blsize = pmp->pm_bpcluster; - rablock = lbn + 1; - if (seqcount > 1 && - de_cn2off(pmp, rablock) < dep->de_FileSize) { - rasize = pmp->pm_bpcluster; - error = breadn(vp, lbn, blsize, - &rablock, &rasize, 1, NOCRED, &bp); + /* XXX what is the best value for crsize? */ + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : blsize * nblks; + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { + error = cluster_read(vp, dep->de_FileSize, lbn, + crsize, NOCRED, uio->uio_resid, seqcount, &bp); } else { - error = bread(vp, lbn, blsize, NOCRED, &bp); + rablock = lbn + 1; + if (seqcount > 1 && + de_cn2off(pmp, rablock) < dep->de_FileSize) { + rasize = pmp->pm_bpcluster; + error = breadn(vp, lbn, blsize, + &rablock, &rasize, 1, NOCRED, &bp); + } else { + error = bread(vp, lbn, blsize, NOCRED, &bp); + } } } if (error) { @@ -580,14 +589,16 @@ break; } on = uio->uio_offset & pmp->pm_crbomask; - diff = pmp->pm_bpcluster - on; - n = diff > uio->uio_resid ? uio->uio_resid : diff; + diff = blsize * nblks - on; + n = blsize * nblks > uio->uio_resid ? uio->uio_resid : blsize * nblks; diff = dep->de_FileSize - uio->uio_offset; - if (diff < n) + if (diff < n) { n = diff; - diff = blsize - bp->b_resid; - if (diff < n) + } + diff = blsize * nblks - bp->b_resid; + if (diff < n) { n = diff; + } error = uiomove(bp->b_data + on, (int) n, uio); brelse(bp); } while (error == 0 && uio->uio_resid > 0 && n != 0); @@ -607,6 +618,7 @@ struct uio *a_uio; int a_ioflag; struct ucred *a_cred; + int seqcount; } */ *ap; { int n; @@ -615,6 +627,7 @@ u_long osize; int error = 0; u_long count; + int seqcount; daddr_t bn, lastcn; struct buf *bp; int ioflag = ap->a_ioflag; @@ -692,7 +705,7 @@ */ if (uio->uio_offset + resid > osize) { count = de_clcount(pmp, uio->uio_offset + resid) - - de_clcount(pmp, osize); + de_clcount(pmp, osize); error = extendfile(dep, count, NULL, NULL, 0); if (error && (error != ENOSPC || (ioflag & IO_UNIT))) goto errexit; @@ -700,6 +713,7 @@ } else lastcn = de_clcount(pmp, osize) - 1; + seqcount = ioflag >> IO_SEQSHIFT; do { if (de_cluster(pmp, uio->uio_offset) > lastcn) { error = ENOSPC; @@ -725,7 +739,7 @@ * then no need to read data from disk. */ bp = getblk(thisvp, bn, pmp->pm_bpcluster, 0, 0, 0); - clrbuf(bp); + vfs_bio_clrbuf(bp); /* * Do the bmap now, since pcbmap needs buffers * for the fat table. (see msdosfs_strategy) @@ -775,6 +789,7 @@ * without delay. Otherwise do a delayed write because we * may want to write somemore into the block later. */ + /* if (ioflag & IO_SYNC) (void) bwrite(bp); else if (n + croffset == pmp->pm_bpcluster) @@ -782,6 +797,24 @@ else bdwrite(bp); dep->de_flag |= DE_UPDATE; + */ + /* + * XXX Patch. + */ + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + bp->b_flags |= B_CLUSTEROK; + if (ioflag & IO_SYNC) + (void)bwrite(bp); + else if (vm_page_count_severe() || buf_dirty_count_severe()) + bawrite(bp); + else if (n + croffset == pmp->pm_bpcluster) { + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + cluster_write(bp, dep->de_FileSize, seqcount); + else + bawrite(bp); + } else + bdwrite(bp); + dep->de_flag |= DE_UPDATE; } while (error == 0 && uio->uio_resid > 0); /* --Boundary-00=_uvdmCBeoNTBAj+g-- From owner-freebsd-usb@FreeBSD.ORG Sun May 29 15:20:08 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 8B57C16A41F for ; Sun, 29 May 2005 15:20:08 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 506A343D49 for ; Sun, 29 May 2005 15:20:08 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4TFK8vr056118 for ; Sun, 29 May 2005 15:20:08 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4TFK8DM056117; Sun, 29 May 2005 15:20:08 GMT (envelope-from gnats) Date: Sun, 29 May 2005 15:20:08 GMT Message-Id: <200505291520.j4TFK8DM056117@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: "Dominic Marks" Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Dominic Marks List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 15:20:08 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: "Dominic Marks" To: Cc: , , Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Sun, 29 May 2005 16:15:48 +0100 This is a multi-part message in MIME format. --Boundary-00=_uvdmCBeoNTBAj+g Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline On Saturday 28 May 2005 15:40, Dominic Marks wrote: > On Saturday 28 May 2005 12:13, Dominic Marks wrote: > > On Saturday 28 May 2005 11:36, Bruce Evans wrote: > > > > > > I use the following to improve transfer rates for msdosfs. The patch > > > is for an old version so it might not apply directly. > > > > > Thanks! I'll try my three tests again with this patch. > > Index: msdosfs_vnops.c > =================================================================== > RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > retrieving revision 1.149.2.1 > diff -u -r1.149.2.1 msdosfs_vnops.c > --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 > +++ msdosfs_vnops.c 28 May 2005 14:26:59 -0000 > @@ -607,6 +607,7 @@ > struct uio *a_uio; > int a_ioflag; > struct ucred *a_cred; > + int seqcount; > } */ *ap; > { > int n; > @@ -615,6 +616,7 @@ > u_long osize; > int error = 0; > u_long count; > + int seqcount; > daddr_t bn, lastcn; > struct buf *bp; > int ioflag = ap->a_ioflag; > @@ -692,7 +694,7 @@ > */ > if (uio->uio_offset + resid > osize) { > count = de_clcount(pmp, uio->uio_offset + resid) - > - de_clcount(pmp, osize); > + de_clcount(pmp, osize); > error = extendfile(dep, count, NULL, NULL, 0); > if (error && (error != ENOSPC || (ioflag & IO_UNIT))) > goto errexit; > @@ -700,6 +702,7 @@ > } else > lastcn = de_clcount(pmp, osize) - 1; > > + seqcount = ioflag >> IO_SEQSHIFT; > do { > if (de_cluster(pmp, uio->uio_offset) > lastcn) { > error = ENOSPC; > @@ -725,7 +728,7 @@ > * then no need to read data from disk. > */ > bp = getblk(thisvp, bn, pmp->pm_bpcluster, 0, 0, 0); > - clrbuf(bp); > + vfs_bio_clrbuf(bp); > /* > * Do the bmap now, since pcbmap needs buffers > * for the fat table. (see msdosfs_strategy) > @@ -775,6 +778,7 @@ > * without delay. Otherwise do a delayed write because we > * may want to write somemore into the block later. > */ > + /* > if (ioflag & IO_SYNC) > (void) bwrite(bp); > else if (n + croffset == pmp->pm_bpcluster) > @@ -782,6 +786,24 @@ > else > bdwrite(bp); > dep->de_flag |= DE_UPDATE; > + */ > + /* > + * XXX Patch. > + */ > + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) > + bp->b_flags |= B_CLUSTEROK; > + if (ioflag & IO_SYNC) > + (void)bwrite(bp); > + else if (vm_page_count_severe() || > buf_dirty_count_severe()) + bawrite(bp); > + else if (n + croffset == pmp->pm_bpcluster) { > + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) > + cluster_write(bp, dep->de_FileSize, > seqcount); + else > + bawrite(bp); > + } else > + bdwrite(bp); > + dep->de_flag |= DE_UPDATE; > } while (error == 0 && uio->uio_resid > 0); > > /* > > Your patch works for me on 5.4-STABLE. It improves write performance > dramatically. I did another test, reading and writing 1GB chunks of data. > Since the patch is to the _write function is it safe to assume the same > method could be used to fix read performance if applied properly in the > correct function? > > Cheers, I have been experimenting in msdosfs_read and I have managed to come up with something that works, but I'm sure it is flawed. On large file reads it will improve read performance (see below) - but only after a long period of the file copy achieving only 3MB/s (see A1). During this time gstat reports the disc itself is reading at its maximum of around 28MB/s. After a long period of low throughput, the disc drops to 25MB/s but the actual transfer rate increases to 25MB/s (see A2). I've tried to narrow it down to something but I'm mostly in the dark, so I'll just hand over what I found to work to review. I looked at Bruce's changes to msdosfs_write and tried to do the same (implement cluster_read) using the ext2 and ffs _read methods as a how-to. I think I'm reading ahead too far, or too early. I have been unable to interpret the gstat output during the first part of the transfer any further. gstat(8) output at the start (slow, A1), and middle (fast, A2) of a large file copy between msdosfs/usb drive (da0s1) and ufs2/ata-100 (ad1). # A1 dT: 0.501 flag_I 500000us sizeof 240 i -1 L(q) ops/s r/s kBps ms/r w/s kBps ms/w %busy Name 14 445 445 28376 24.7 0 0 0.0 99.9| da0 0 28 0 0 0.0 28 3578 1.7 4.8| ad1 0 28 0 0 0.0 28 3578 1.7 4.8| ad1s1 14 445 445 28376 24.9 0 0 0.0 100.0| da0s1 After 30-45 seconds (1GB test file): # A2 dT: 0.501 flag_I 500000us sizeof 240 i -1 L(q) ops/s r/s kBps ms/r w/s kBps ms/w %busy Name 1 403 403 25428 2.1 0 0 0.0 85.0| da0 0 199 0 0 0.0 199 25532 1.7 34.0| ad1 0 199 0 0 0.0 199 25532 1.7 34.1| ad1s1 1 403 403 25428 2.1 0 0 0.0 85.9| da0s1 The patch which combines Bruce's original patch for msdosfs_write, revised for current text positions, and my attempts to do the same for msdosfs_read. %% Index: msdosfs_vnops.c =================================================================== RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v retrieving revision 1.149.2.1 diff -u -r1.149.2.1 msdosfs_vnops.c --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 @@ -517,6 +517,8 @@ int blsize; int isadir; int orig_resid; + int nblks = 16; /* XXX should be defined, but not here */ + int crsize; u_int n; u_long diff; u_long on; @@ -565,14 +567,21 @@ error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); } else { blsize = pmp->pm_bpcluster; - rablock = lbn + 1; - if (seqcount > 1 && - de_cn2off(pmp, rablock) < dep->de_FileSize) { - rasize = pmp->pm_bpcluster; - error = breadn(vp, lbn, blsize, - &rablock, &rasize, 1, NOCRED, &bp); + /* XXX what is the best value for crsize? */ + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : blsize * nblks; + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { + error = cluster_read(vp, dep->de_FileSize, lbn, + crsize, NOCRED, uio->uio_resid, seqcount, &bp); } else { - error = bread(vp, lbn, blsize, NOCRED, &bp); + rablock = lbn + 1; + if (seqcount > 1 && + de_cn2off(pmp, rablock) < dep->de_FileSize) { + rasize = pmp->pm_bpcluster; + error = breadn(vp, lbn, blsize, + &rablock, &rasize, 1, NOCRED, &bp); + } else { + error = bread(vp, lbn, blsize, NOCRED, &bp); + } } } if (error) { @@ -580,14 +589,16 @@ break; } on = uio->uio_offset & pmp->pm_crbomask; - diff = pmp->pm_bpcluster - on; - n = diff > uio->uio_resid ? uio->uio_resid : diff; + diff = blsize * nblks - on; + n = blsize * nblks > uio->uio_resid ? uio->uio_resid : blsize * nblks; diff = dep->de_FileSize - uio->uio_offset; - if (diff < n) + if (diff < n) { n = diff; - diff = blsize - bp->b_resid; - if (diff < n) + } + diff = blsize * nblks - bp->b_resid; + if (diff < n) { n = diff; + } error = uiomove(bp->b_data + on, (int) n, uio); brelse(bp); } while (error == 0 && uio->uio_resid > 0 && n != 0); @@ -607,6 +618,7 @@ struct uio *a_uio; int a_ioflag; struct ucred *a_cred; + int seqcount; } */ *ap; { int n; @@ -615,6 +627,7 @@ u_long osize; int error = 0; u_long count; + int seqcount; daddr_t bn, lastcn; struct buf *bp; int ioflag = ap->a_ioflag; @@ -692,7 +705,7 @@ */ if (uio->uio_offset + resid > osize) { count = de_clcount(pmp, uio->uio_offset + resid) - - de_clcount(pmp, osize); + de_clcount(pmp, osize); error = extendfile(dep, count, NULL, NULL, 0); if (error && (error != ENOSPC || (ioflag & IO_UNIT))) goto errexit; @@ -700,6 +713,7 @@ } else lastcn = de_clcount(pmp, osize) - 1; + seqcount = ioflag >> IO_SEQSHIFT; do { if (de_cluster(pmp, uio->uio_offset) > lastcn) { error = ENOSPC; @@ -725,7 +739,7 @@ * then no need to read data from disk. */ bp = getblk(thisvp, bn, pmp->pm_bpcluster, 0, 0, 0); - clrbuf(bp); + vfs_bio_clrbuf(bp); /* * Do the bmap now, since pcbmap needs buffers * for the fat table. (see msdosfs_strategy) @@ -775,6 +789,7 @@ * without delay. Otherwise do a delayed write because we * may want to write somemore into the block later. */ + /* if (ioflag & IO_SYNC) (void) bwrite(bp); else if (n + croffset == pmp->pm_bpcluster) @@ -782,6 +797,24 @@ else bdwrite(bp); dep->de_flag |= DE_UPDATE; + */ + /* + * XXX Patch. + */ + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + bp->b_flags |= B_CLUSTEROK; + if (ioflag & IO_SYNC) + (void)bwrite(bp); + else if (vm_page_count_severe() || buf_dirty_count_severe()) + bawrite(bp); + else if (n + croffset == pmp->pm_bpcluster) { + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + cluster_write(bp, dep->de_FileSize, seqcount); + else + bawrite(bp); + } else + bdwrite(bp); + dep->de_flag |= DE_UPDATE; } while (error == 0 && uio->uio_resid > 0); /* %% With this patch I can get the following transfer rates: msdosfs reading # ls -lh /mnt/random2.file -rwxr-xr-x 1 root wheel 1.0G May 29 11:24 /mnt/random2.file # /usr/bin/time -al cp /mnt/random2.file /vol 59.61 real 0.05 user 6.79 sys 632 maximum resident set size 11 average shared memory size 80 average unshared data size 123 average unshared stack size 88 page reclaims 0 page faults 0 swaps 23757 block input operations ** 8192 block output operations 0 messages sent 0 messages received 0 signals received 16660 voluntary context switches 10387 involuntary context switches Average Rate: 15.31MB/s. (Would be higher if not for the slow start) ** This figure is 3x that of the UFS2 operations. This must be a indicator of what I'm doing wrong, but I don't know what. msdosfs writing # /usr/bin/time -al cp /vol/random2.file /mnt 47.33 real 0.03 user 7.13 sys 632 maximum resident set size 12 average shared memory size 85 average unshared data size 130 average unshared stack size 88 page reclaims 0 page faults 0 swaps 8735 block input operations 16385 block output operations 0 messages sent 0 messages received 0 signals received 8856 voluntary context switches 29631 involuntary context switches Average Rate: 18.79MB/s. To compare with UFS2 + softupdates on the same system / disc. ufs2 reading # /usr/bin/time -al cp /mnt/random2.file /vol 42.39 real 0.02 user 6.61 sys 632 maximum resident set size 12 average shared memory size 87 average unshared data size 133 average unshared stack size 88 page reclaims 0 page faults 0 swaps 8249 block input operations 8193 block output operations 0 messages sent 0 messages received 0 signals received 8246 voluntary context switches 24617 involuntary context switches Average Rate: 20.89MB/s. ufs2 writing # /usr/bin/time -al cp /vol/random2.file /mnt/ 47.12 real 0.03 user 6.74 sys 632 maximum resident set size 12 average shared memory size 85 average unshared data size 130 average unshared stack size 88 page reclaims 0 page faults 0 swaps 8260 block input operations 8192 block output operations 0 messages sent 0 messages received 0 signals received 8303 voluntary context switches 24700 involuntary context switches Average Rate: 19MB/s. I'd hope that someone could point me in the right direction so I can clean the patch up, or finish this off themselves and commit it (or something else which will increase the read/write speed). Thanks very much, -- Dominic GoodforBusiness.co.uk I.T. Services for SMEs in the UK. --Boundary-00=_uvdmCBeoNTBAj+g Content-Type: text/x-diff; charset="iso-8859-1"; name="msdos-perf-releng5.patch" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="msdos-perf-releng5.patch" Index: msdosfs_vnops.c =================================================================== RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v retrieving revision 1.149.2.1 diff -u -r1.149.2.1 msdosfs_vnops.c --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 @@ -517,6 +517,8 @@ int blsize; int isadir; int orig_resid; + int nblks = 16; /* XXX should be defined, but not here */ + int crsize; u_int n; u_long diff; u_long on; @@ -565,14 +567,21 @@ error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); } else { blsize = pmp->pm_bpcluster; - rablock = lbn + 1; - if (seqcount > 1 && - de_cn2off(pmp, rablock) < dep->de_FileSize) { - rasize = pmp->pm_bpcluster; - error = breadn(vp, lbn, blsize, - &rablock, &rasize, 1, NOCRED, &bp); + /* XXX what is the best value for crsize? */ + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : blsize * nblks; + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { + error = cluster_read(vp, dep->de_FileSize, lbn, + crsize, NOCRED, uio->uio_resid, seqcount, &bp); } else { - error = bread(vp, lbn, blsize, NOCRED, &bp); + rablock = lbn + 1; + if (seqcount > 1 && + de_cn2off(pmp, rablock) < dep->de_FileSize) { + rasize = pmp->pm_bpcluster; + error = breadn(vp, lbn, blsize, + &rablock, &rasize, 1, NOCRED, &bp); + } else { + error = bread(vp, lbn, blsize, NOCRED, &bp); + } } } if (error) { @@ -580,14 +589,16 @@ break; } on = uio->uio_offset & pmp->pm_crbomask; - diff = pmp->pm_bpcluster - on; - n = diff > uio->uio_resid ? uio->uio_resid : diff; + diff = blsize * nblks - on; + n = blsize * nblks > uio->uio_resid ? uio->uio_resid : blsize * nblks; diff = dep->de_FileSize - uio->uio_offset; - if (diff < n) + if (diff < n) { n = diff; - diff = blsize - bp->b_resid; - if (diff < n) + } + diff = blsize * nblks - bp->b_resid; + if (diff < n) { n = diff; + } error = uiomove(bp->b_data + on, (int) n, uio); brelse(bp); } while (error == 0 && uio->uio_resid > 0 && n != 0); @@ -607,6 +618,7 @@ struct uio *a_uio; int a_ioflag; struct ucred *a_cred; + int seqcount; } */ *ap; { int n; @@ -615,6 +627,7 @@ u_long osize; int error = 0; u_long count; + int seqcount; daddr_t bn, lastcn; struct buf *bp; int ioflag = ap->a_ioflag; @@ -692,7 +705,7 @@ */ if (uio->uio_offset + resid > osize) { count = de_clcount(pmp, uio->uio_offset + resid) - - de_clcount(pmp, osize); + de_clcount(pmp, osize); error = extendfile(dep, count, NULL, NULL, 0); if (error && (error != ENOSPC || (ioflag & IO_UNIT))) goto errexit; @@ -700,6 +713,7 @@ } else lastcn = de_clcount(pmp, osize) - 1; + seqcount = ioflag >> IO_SEQSHIFT; do { if (de_cluster(pmp, uio->uio_offset) > lastcn) { error = ENOSPC; @@ -725,7 +739,7 @@ * then no need to read data from disk. */ bp = getblk(thisvp, bn, pmp->pm_bpcluster, 0, 0, 0); - clrbuf(bp); + vfs_bio_clrbuf(bp); /* * Do the bmap now, since pcbmap needs buffers * for the fat table. (see msdosfs_strategy) @@ -775,6 +789,7 @@ * without delay. Otherwise do a delayed write because we * may want to write somemore into the block later. */ + /* if (ioflag & IO_SYNC) (void) bwrite(bp); else if (n + croffset == pmp->pm_bpcluster) @@ -782,6 +797,24 @@ else bdwrite(bp); dep->de_flag |= DE_UPDATE; + */ + /* + * XXX Patch. + */ + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + bp->b_flags |= B_CLUSTEROK; + if (ioflag & IO_SYNC) + (void)bwrite(bp); + else if (vm_page_count_severe() || buf_dirty_count_severe()) + bawrite(bp); + else if (n + croffset == pmp->pm_bpcluster) { + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERW) == 0) + cluster_write(bp, dep->de_FileSize, seqcount); + else + bawrite(bp); + } else + bdwrite(bp); + dep->de_flag |= DE_UPDATE; } while (error == 0 && uio->uio_resid > 0); /* --Boundary-00=_uvdmCBeoNTBAj+g Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Content-Disposition: attachment _______________________________________________ freebsd-fs@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-fs To unsubscribe, send any mail to "freebsd-fs-unsubscribe@freebsd.org" --Boundary-00=_uvdmCBeoNTBAj+g-- From owner-freebsd-usb@FreeBSD.ORG Sun May 29 16:10:05 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 57F6716A41C for ; Sun, 29 May 2005 16:10:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 2AF5B43D1F for ; Sun, 29 May 2005 16:10:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4TGA5CU062735 for ; Sun, 29 May 2005 16:10:05 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4TGA4iK062734; Sun, 29 May 2005 16:10:04 GMT (envelope-from gnats) Date: Sun, 29 May 2005 16:10:04 GMT Message-Id: <200505291610.j4TGA4iK062734@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Gerrit =?iso-8859-1?Q?K=FChn?= Cc: Subject: Re: usb/81621 external hd hangs under load on ehci X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Gerrit =?iso-8859-1?Q?K=FChn?= List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 16:10:05 -0000 The following reply was made to PR usb/81621; it has been noted by GNATS. From: Gerrit =?iso-8859-1?Q?K=FChn?= To: bug-followup@freebsd.org Cc: Subject: Re: usb/81621 external hd hangs under load on ehci Date: Sun, 29 May 2005 18:07:56 +0200 I did some further testing and found out that the disk hangs on my usb1 ports, too. It just takes longer time to provoke this. When it hangs, I can occasionally see the following in my syslog: May 29 17:01:13 stardust kernel: umass0: BBB reset failed, TIMEOUT May 29 17:09:53 stardust kernel: umass0: BBB reset failed, TIMEOUT May 29 17:09:53 stardust last message repeated 3 times May 29 17:21:12 stardust last message repeated 5 times May 29 17:30:21 stardust last message repeated 4 times May 29 17:35:10 stardust last message repeated 2 times When I finally decided to unplug the device (unmounting was not possible), the whole system rebooted (which is possible a consequence of the still mounted fs, but annoying anyway): May 29 17:35:58 stardust kernel: (da1:umass-sim0:0:0:0): lost device May 29 17:35:58 stardust kernel: (da2:umass-sim0:0:0:1): lost device May 29 17:35:58 stardust kernel: (da2:umass-sim0:0:0:1): removing device entry May 29 17:35:58 stardust kernel: (da3:umass-sim0:0:0:2): lost device May 29 17:35:58 stardust kernel: (da3:umass-sim0:0:0:2): removing device entry May 29 17:35:58 stardust kernel: (da4:umass-sim0:0:0:3): lost device May 29 17:35:58 stardust kernel: (da4:umass-sim0:0:0:3): removing device entry May 29 17:35:58 stardust kernel: umass0: detached May 29 17:35:58 stardust kernel: fsync: giving up on dirty: 0xc3fc8528: tag msdo sfs, type VREG, usecount 1, writecount 0, refcount 1, flags (VV_OBJBUF), lock ty pe msdosfs: EXCL (count 1) by thread 0xc3c7f600 (pid 1307) May 29 17:35:58 stardust kernel: startcluster 9760198, dircluster 746251, diroff set 1344, on dev (4, 45) May 29 17:35:58 stardust kernel: fsync: giving up on dirty: 0xc3fc9738: tag msdo sfs, type VREG, usecount 1, writecount 0, refcount 1054, flags (VV_OBJBUF), lock type msdosfs: EXCL (count 1) by thread 0xc3c7f600 (pid 1307) Since I can see this problem on two different machines with altogether four different chipsets (two usb1, two usb2) I think the problem is the XS-Drive itself. Maybe there are other/more quirks needed? Here is how it shows up in syslog: May 29 18:03:14 stardust kernel: umass0: PNY USB, rev 2.00/1.00, addr 2 May 29 18:03:15 stardust kernel: da1 at umass-sim0 bus 0 target 0 lun 0 May 29 18:03:15 stardust kernel: da1: Removable Direct Access SCS I-0 device May 29 18:03:15 stardust kernel: da1: 40.000MB/s transfers May 29 18:03:15 stardust kernel: da1: 38204MB (78242976 512 byte sectors: 255H 6 3S/T 4870C) May 29 18:03:15 stardust kernel: da2 at umass-sim0 bus 0 target 0 lun 1 May 29 18:03:15 stardust kernel: da2: Removable Direct Access SCS I-0 device May 29 18:03:15 stardust kernel: da2: 40.000MB/s transfers May 29 18:03:15 stardust kernel: da2: Attempt to query device size failed: NOT R EADY, Medium not present May 29 18:03:15 stardust kernel: da3 at umass-sim0 bus 0 target 0 lun 2 May 29 18:03:15 stardust kernel: da3: Removable Direct Access SCS I-0 device May 29 18:03:15 stardust kernel: da3: 40.000MB/s transfers May 29 18:03:15 stardust kernel: da3: Attempt to query device size failed: NOT R EADY, Medium not present May 29 18:03:15 stardust kernel: da4 at umass-sim0 bus 0 target 0 lun 3 May 29 18:03:15 stardust kernel: da4: Removable Direct Access SCS I-0 device May 29 18:03:15 stardust kernel: da4: 40.000MB/s transfers May 29 18:03:15 stardust kernel: da4: Attempt to query device size failed: NOT R EADY, Medium not present usbdevs says Controller /dev/usb4: addr 1: high speed, self powered, config 1, EHCI root hub(0x0000), NEC(0x0000), rev 1.00 port 1 powered port 2 powered port 3 powered port 4 powered port 5 addr 2: high speed, power 350 mA, config 1, USB(0x1270), PNY(0x0d7d), rev 1.00 Is there any further info I could provide? cu Gerrit -- From owner-freebsd-usb@FreeBSD.ORG Sun May 29 18:22:20 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 6F33716A41C for ; Sun, 29 May 2005 18:22:20 +0000 (GMT) (envelope-from sigsegv@radiotube.org) Received: from enterprise.localnet.radiotube.org (enterprise.radiotube.org [81.0.166.237]) by mx1.FreeBSD.org (Postfix) with ESMTP id 76F4843D48 for ; Sun, 29 May 2005 18:22:18 +0000 (GMT) (envelope-from sigsegv@radiotube.org) Received: from [10.53.4.10] ([10.53.4.10]) (authenticated bits=0) by enterprise.localnet.radiotube.org (8.13.1/8.13.1) with ESMTP id j4TILxp4059581 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO); Sun, 29 May 2005 20:22:03 +0200 (CEST) (envelope-from sigsegv@radiotube.org) Message-ID: <429A088B.1090405@radiotube.org> Date: Sun, 29 May 2005 20:23:07 +0200 From: Jan-Espen Pettersen User-Agent: Mozilla Thunderbird 1.0.2 (X11/20050329) X-Accept-Language: en-us, en MIME-Version: 1.0 To: Ian Dowse References: <200505291310.aa19689@nowhere.iedowse.com> In-Reply-To: <200505291310.aa19689@nowhere.iedowse.com> X-Enigmail-Version: 0.91.0.0 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Cc: freebsd-usb@freebsd.org Subject: Re: ulpt_tick after close X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: sigsegv@radiotube.org List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 29 May 2005 18:22:20 -0000 Ian Dowse wrote: >In message <42998B18.8020806@radiotube.org>, Jan-Espen Pettersen writes: > > >>I think I'll replace that printf with a panic in ulpt_read_cb to get a >>backtrace next time. (And at the same time update my sources) As it >>would reveal what is actually calling ulpt_read_cb after the callout has >>been stopped. The problem is that this is very unlikely to happen during >>a single print job, but it does over time, so it might take me some time >>to get that backtrace. >> >> > >Thanks for the details. By the way, is it lpd or something else >that is actually accessing the ulpt device? Below is a patch you >could try that will hopefully find out a bit more about what is >going on. You could also change the new return statement in >ulpt_read_cb() to a panic, as the stack trace might reveal more >information like you say. > > It is cups from ports. Thank you very much. Jan-Espen Pettersen From owner-freebsd-usb@FreeBSD.ORG Mon May 30 07:20:05 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id C4A1216A41C for ; Mon, 30 May 2005 07:20:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 8E48A43D1D for ; Mon, 30 May 2005 07:20:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4U7K5hm005159 for ; Mon, 30 May 2005 07:20:05 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4U7K5Qh005158; Mon, 30 May 2005 07:20:05 GMT (envelope-from gnats) Date: Mon, 30 May 2005 07:20:05 GMT Message-Id: <200505300720.j4U7K5Qh005158@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Bruce Evans Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Bruce Evans List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 07:20:05 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: Bruce Evans To: Dominic Marks Cc: freebsd-gnats-submit@FreeBSD.org, banhalmi@field.hu, freebsd-fs@FreeBSD.org Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Mon, 30 May 2005 17:19:22 +1000 (EST) On Sun, 29 May 2005, Dominic Marks wrote: > I have been experimenting in msdosfs_read and I have managed to come up with > something that works, but I'm sure it is flawed. On large file reads it will > improve read performance (see below) - but only after a long period of the > file copy achieving only 3MB/s (see A1). During this time gstat reports the > disc itself is reading at its maximum of around 28MB/s. After a long period > of low throughput, the disc drops to 25MB/s but the actual transfer rate > increases to 25MB/s (see A2). A1 is strange. It might be reading too much ahead, but I wouldn't expect the read-ahead to be discarded soon so this should make little difference for reading whole files. > I've tried to narrow it down to something but I'm mostly in the dark, so I'll > just hand over what I found to work to review. I looked at Bruce's changes to > msdosfs_write and tried to do the same (implement cluster_read) using the > ext2 and ffs _read methods as a how-to. I think I'm reading ahead too far, or > too early. I have been unable to interpret the gstat output during the first > part of the transfer any further. The ext2 and ffs methods are a good place to start. Also look at cd9660 -- it is a little simpler. > The patch which combines Bruce's original patch for msdosfs_write, revised for > current text positions, and my attempts to do the same for msdosfs_read. > > %% > Index: msdosfs_vnops.c > =================================================================== > RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > retrieving revision 1.149.2.1 > diff -u -r1.149.2.1 msdosfs_vnops.c > --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 > +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 > @@ -565,14 +567,21 @@ > error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); > } else { > blsize = pmp->pm_bpcluster; > - rablock = lbn + 1; > - if (seqcount > 1 && > - de_cn2off(pmp, rablock) < dep->de_FileSize) { > - rasize = pmp->pm_bpcluster; > - error = breadn(vp, lbn, blsize, > - &rablock, &rasize, 1, NOCRED, &bp); > + /* XXX what is the best value for crsize? */ > + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : blsize * nblks; > + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { > + error = cluster_read(vp, dep->de_FileSize, lbn, > + crsize, NOCRED, uio->uio_resid, seqcount, &bp); crsize should be just the block size (cluster size in msdosfs and blsize variable here) according to this code in all other file systems. seqcount gives the amount of readahead and there are algorithms elsewhere to guess its best value. I think cluster_read() reads only physically contiguous blocks, so the amount of read-ahead for it is not critical for the clustered case anyway. There will either be a large range of contigous blocks, in which case reading ahead a lot isn't bad, or read-ahead will be limited by discontiguities. Giving a too-large value for crsize may be harmful by confusing cluster_read() about discontiguities, or just by asking it to read the large size when the blocks actually in the file aren't contiguous. I think the above handles most cases, so look for problems there first. > } else { The above seems to be missing a bread() for the EOF case (before the else). I don't know what cluster_read() does at EOF. See cd9660_read() for clear code. (Here there is unfortunately an extra level of indentation from a special case for directories.) > - error = bread(vp, lbn, blsize, NOCRED, &bp); > + rablock = lbn + 1; > + if (seqcount > 1 && > + de_cn2off(pmp, rablock) < dep->de_FileSize) { > + rasize = pmp->pm_bpcluster; > + error = breadn(vp, lbn, blsize, > + &rablock, &rasize, 1, NOCRED, &bp); > + } else { > + error = bread(vp, lbn, blsize, NOCRED, &bp); > + } This part seems to be OK. (It is just the old code indented.) > } > } > if (error) { > ... > %% > > With this patch I can get the following transfer rates: > > msdosfs reading > > # ls -lh /mnt/random2.file > -rwxr-xr-x 1 root wheel 1.0G May 29 11:24 /mnt/random2.file > > # /usr/bin/time -al cp /mnt/random2.file /vol > 59.61 real 0.05 user 6.79 sys > 632 maximum resident set size > 11 average shared memory size > 80 average unshared data size > 123 average unshared stack size > 88 page reclaims > 0 page faults > 0 swaps > 23757 block input operations ** > 8192 block output operations > 0 messages sent > 0 messages received > 0 signals received > 16660 voluntary context switches > 10387 involuntary context switches > > Average Rate: 15.31MB/s. (Would be higher if not for the slow start) > > ** This figure is 3x that of the UFS2 operations. This must be a indicator of > what I'm doing wrong, but I don't know what. This might also be a sign of fragmentation due to bad allocation policies at write time or write() not being able to do good allocation due to previous fragmentation. The average rate isn't too bad, despite the extra blocks. > msdosfs writing > > # /usr/bin/time -al cp /vol/random2.file /mnt > 47.33 real 0.03 user 7.13 sys > 632 maximum resident set size > 12 average shared memory size > 85 average unshared data size > 130 average unshared stack size > 88 page reclaims > 0 page faults > 0 swaps > 8735 block input operations > 16385 block output operations > 0 messages sent > 0 messages received > 0 signals received > 8856 voluntary context switches > 29631 involuntary context switches > > Average Rate: 18.79MB/s. There are 2x as many blocks as for ffs2 for writing instead of 3x for reading. What are the input blocks for here? Better put the non-msdosfs part of the source or target in memory so that it doesn't get counted. Or try mount -v (it gives sync and async read/write counts for individual file systems). 2x is actually believable while ffs2's counts aren't. It corresponds to a block size of 64K, which is what I would expect for the unfragmented case. > To compare with UFS2 + softupdates on the same system / disc. > > ufs2 reading > > # /usr/bin/time -al cp /mnt/random2.file /vol > 42.39 real 0.02 user 6.61 sys > 632 maximum resident set size > 12 average shared memory size > 87 average unshared data size > 133 average unshared stack size > 88 page reclaims > 0 page faults > 0 swaps > 8249 block input operations > 8193 block output operations > 0 messages sent > 0 messages received > 0 signals received > 8246 voluntary context switches > 24617 involuntary context switches > > Average Rate: 20.89MB/s. Isn't it 24.16MB/s? 8192 i/o operations seems to be too small. It corresponds to a block size of 128K. Most drivers don't actually support doing i/o of that size (most have a limit of 64K), so if they get asked to then it is a bug. This bug is common or ubiquitous. The block size to use for clusters is in mnt_iosize_max, and this is set in various wrong ways, often or always to MAXPHYS = 128K. This usually makes little difference except to give misleading statistics. Clustering tends to produce blocks of size 128K and the block i/o counts report blocks of that sizes, but smaller blocks are sent to the hardware. I'm not sure if libdevstat() sees the smaller blocks. I think it doesn't. > [... ufs2 writing similar to reading] Bruce From owner-freebsd-usb@FreeBSD.ORG Mon May 30 07:40:05 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 6A97216A41C for ; Mon, 30 May 2005 07:40:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 324CB43D1F for ; Mon, 30 May 2005 07:40:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4U7e4D3006815 for ; Mon, 30 May 2005 07:40:04 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4U7e4Lx006814; Mon, 30 May 2005 07:40:04 GMT (envelope-from gnats) Date: Mon, 30 May 2005 07:40:04 GMT Message-Id: <200505300740.j4U7e4Lx006814@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: "Bruce Evans" Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Bruce Evans List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 07:40:05 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: "Bruce Evans" To: Cc: , , Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Mon, 30 May 2005 08:30:53 +0100 On Sun, 29 May 2005, Dominic Marks wrote: > I have been experimenting in msdosfs_read and I have managed to come up with > something that works, but I'm sure it is flawed. On large file reads it will > improve read performance (see below) - but only after a long period of the > file copy achieving only 3MB/s (see A1). During this time gstat reports the > disc itself is reading at its maximum of around 28MB/s. After a long period > of low throughput, the disc drops to 25MB/s but the actual transfer rate > increases to 25MB/s (see A2). A1 is strange. It might be reading too much ahead, but I wouldn't expect the read-ahead to be discarded soon so this should make little difference for reading whole files. > I've tried to narrow it down to something but I'm mostly in the dark, so I'll > just hand over what I found to work to review. I looked at Bruce's changes to > msdosfs_write and tried to do the same (implement cluster_read) using the > ext2 and ffs _read methods as a how-to. I think I'm reading ahead too far, or > too early. I have been unable to interpret the gstat output during the first > part of the transfer any further. The ext2 and ffs methods are a good place to start. Also look at cd9660 -- it is a little simpler. > The patch which combines Bruce's original patch for msdosfs_write, revised for > current text positions, and my attempts to do the same for msdosfs_read. > > %% > Index: msdosfs_vnops.c > =================================================================== > RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > retrieving revision 1.149.2.1 > diff -u -r1.149.2.1 msdosfs_vnops.c > --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 > +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 > @@ -565,14 +567,21 @@ > error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); > } else { > blsize = pmp->pm_bpcluster; > - rablock = lbn + 1; > - if (seqcount > 1 && > - de_cn2off(pmp, rablock) < dep->de_FileSize) { > - rasize = pmp->pm_bpcluster; > - error = breadn(vp, lbn, blsize, > - &rablock, &rasize, 1, NOCRED, &bp); > + /* XXX what is the best value for crsize? */ > + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : blsize * nblks; > + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { > + error = cluster_read(vp, dep->de_FileSize, lbn, > + crsize, NOCRED, uio->uio_resid, seqcount, &bp); crsize should be just the block size (cluster size in msdosfs and blsize variable here) according to this code in all other file systems. seqcount gives the amount of readahead and there are algorithms elsewhere to guess its best value. I think cluster_read() reads only physically contiguous blocks, so the amount of read-ahead for it is not critical for the clustered case anyway. There will either be a large range of contigous blocks, in which case reading ahead a lot isn't bad, or read-ahead will be limited by discontiguities. Giving a too-large value for crsize may be harmful by confusing cluster_read() about discontiguities, or just by asking it to read the large size when the blocks actually in the file aren't contiguous. I think the above handles most cases, so look for problems there first. > } else { The above seems to be missing a bread() for the EOF case (before the else). I don't know what cluster_read() does at EOF. See cd9660_read() for clear code. (Here there is unfortunately an extra level of indentation from a special case for directories.) > - error = bread(vp, lbn, blsize, NOCRED, &bp); > + rablock = lbn + 1; > + if (seqcount > 1 && > + de_cn2off(pmp, rablock) < dep->de_FileSize) { > + rasize = pmp->pm_bpcluster; > + error = breadn(vp, lbn, blsize, > + &rablock, &rasize, 1, NOCRED, &bp); > + } else { > + error = bread(vp, lbn, blsize, NOCRED, &bp); > + } This part seems to be OK. (It is just the old code indented.) > } > } > if (error) { > ... > %% > > With this patch I can get the following transfer rates: > > msdosfs reading > > # ls -lh /mnt/random2.file > -rwxr-xr-x 1 root wheel 1.0G May 29 11:24 /mnt/random2.file > > # /usr/bin/time -al cp /mnt/random2.file /vol > 59.61 real 0.05 user 6.79 sys > 632 maximum resident set size > 11 average shared memory size > 80 average unshared data size > 123 average unshared stack size > 88 page reclaims > 0 page faults > 0 swaps > 23757 block input operations ** > 8192 block output operations > 0 messages sent > 0 messages received > 0 signals received > 16660 voluntary context switches > 10387 involuntary context switches > > Average Rate: 15.31MB/s. (Would be higher if not for the slow start) > > ** This figure is 3x that of the UFS2 operations. This must be a indicator of > what I'm doing wrong, but I don't know what. This might also be a sign of fragmentation due to bad allocation policies at write time or write() not being able to do good allocation due to previous fragmentation. The average rate isn't too bad, despite the extra blocks. > msdosfs writing > > # /usr/bin/time -al cp /vol/random2.file /mnt > 47.33 real 0.03 user 7.13 sys > 632 maximum resident set size > 12 average shared memory size > 85 average unshared data size > 130 average unshared stack size > 88 page reclaims > 0 page faults > 0 swaps > 8735 block input operations > 16385 block output operations > 0 messages sent > 0 messages received > 0 signals received > 8856 voluntary context switches > 29631 involuntary context switches > > Average Rate: 18.79MB/s. There are 2x as many blocks as for ffs2 for writing instead of 3x for reading. What are the input blocks for here? Better put the non-msdosfs part of the source or target in memory so that it doesn't get counted. Or try mount -v (it gives sync and async read/write counts for individual file systems). 2x is actually believable while ffs2's counts aren't. It corresponds to a block size of 64K, which is what I would expect for the unfragmented case. > To compare with UFS2 + softupdates on the same system / disc. > > ufs2 reading > > # /usr/bin/time -al cp /mnt/random2.file /vol > 42.39 real 0.02 user 6.61 sys > 632 maximum resident set size > 12 average shared memory size > 87 average unshared data size > 133 average unshared stack size > 88 page reclaims > 0 page faults > 0 swaps > 8249 block input operations > 8193 block output operations > 0 messages sent > 0 messages received > 0 signals received > 8246 voluntary context switches > 24617 involuntary context switches > > Average Rate: 20.89MB/s. Isn't it 24.16MB/s? 8192 i/o operations seems to be too small. It corresponds to a block size of 128K. Most drivers don't actually support doing i/o of that size (most have a limit of 64K), so if they get asked to then it is a bug. This bug is common or ubiquitous. The block size to use for clusters is in mnt_iosize_max, and this is set in various wrong ways, often or always to MAXPHYS = 128K. This usually makes little difference except to give misleading statistics. Clustering tends to produce blocks of size 128K and the block i/o counts report blocks of that sizes, but smaller blocks are sent to the hardware. I'm not sure if libdevstat() sees the smaller blocks. I think it doesn't. > [... ufs2 writing similar to reading] Bruce _______________________________________________ freebsd-fs@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-fs To unsubscribe, send any mail to "freebsd-fs-unsubscribe@freebsd.org" From owner-freebsd-usb@FreeBSD.ORG Mon May 30 10:20:05 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id D222916A41C for ; Mon, 30 May 2005 10:20:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 9460B43D54 for ; Mon, 30 May 2005 10:20:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4UAK5qo026862 for ; Mon, 30 May 2005 10:20:05 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4UAK5i6026861; Mon, 30 May 2005 10:20:05 GMT (envelope-from gnats) Date: Mon, 30 May 2005 10:20:05 GMT Message-Id: <200505301020.j4UAK5i6026861@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Bruce Evans Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Bruce Evans List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 10:20:06 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: Bruce Evans To: Dominic Marks Cc: freebsd-fs@freebsd.org, freebsd-gnats-submit@freebsd.org, banhalmi@field.hu Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Mon, 30 May 2005 20:11:45 +1000 (EST) On Mon, 30 May 2005, Bruce Evans wrote: > On Sun, 29 May 2005, Dominic Marks wrote: >> I have been experimenting in msdosfs_read and I have managed to come up >> with >> something that works, but I'm sure it is flawed. On large file reads it >> will >> ... >> %% >> Index: msdosfs_vnops.c >> =================================================================== >> RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v >> retrieving revision 1.149.2.1 >> diff -u -r1.149.2.1 msdosfs_vnops.c >> --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 >> +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 >> @@ -565,14 +567,21 @@ >> error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, >> &bp); >> } else { >> blsize = pmp->pm_bpcluster; >> - rablock = lbn + 1; >> - if (seqcount > 1 && >> - de_cn2off(pmp, rablock) < dep->de_FileSize) { >> - rasize = pmp->pm_bpcluster; >> - error = breadn(vp, lbn, blsize, >> - &rablock, &rasize, 1, NOCRED, &bp); >> + /* XXX what is the best value for crsize? */ >> + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : >> blsize * nblks; >> + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { >> + error = cluster_read(vp, dep->de_FileSize, >> lbn, >> + crsize, NOCRED, uio->uio_resid, >> seqcount, &bp); > > crsize should be just the block size (cluster size in msdosfs and > blsize variable here) according to this code in all other file systems. > ... The main problem is that VOP_BMAP() is not fully implemented for msdosfs. msdosfs_bmap() only has a stub which pretends that clustering ins never possible: % /* % * vp - address of vnode file the file % * bn - which cluster we are interested in mapping to a filesystem block number. % * vpp - returns the vnode for the block special file holding the filesystem % * containing the file of interest % * bnp - address of where to return the filesystem relative block number % */ This comment rotted in 1994 when 4.4BSD packed the args into a struct and added the a_runp and a_runb args to support clustering. % static int % msdosfs_bmap(ap) % struct vop_bmap_args /* { % struct vnode *a_vp; % daddr_t a_bn; % struct vnode **a_vpp; % daddr_t *a_bnp; % int *a_runp; % int *a_runb; % } */ *ap; % { % struct denode *dep = VTODE(ap->a_vp); % daddr_t blkno; % int error; % % if (ap->a_vpp != NULL) % *ap->a_vpp = dep->de_devvp; % if (ap->a_bnp == NULL) % return (0); % if (ap->a_runp) { % /* % * Sequential clusters should be counted here. ^^^^^^^^^ % */ % *ap->a_runp = 0; % } % if (ap->a_runb) { % *ap->a_runb = 0; % } % error = pcbmap(dep, ap->a_bn, &blkno, 0, 0); % *ap->a_bnp = blkno; % return (error); % } Here is a cleaned up version of the patch to add (not actually working) clustering to msdosfs_read(). %%% Index: msdosfs_vnops.c =================================================================== RCS file: /home/ncvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v retrieving revision 1.147 diff -u -2 -r1.147 msdosfs_vnops.c --- msdosfs_vnops.c 4 Feb 2004 21:52:53 -0000 1.147 +++ msdosfs_vnops.c 30 May 2005 08:57:02 -0000 @@ -541,5 +555,7 @@ if (uio->uio_offset >= dep->de_FileSize) break; + blsize = pmp->pm_bpcluster; lbn = de_cluster(pmp, uio->uio_offset); + rablock = lbn + 1; /* * If we are operating on a directory file then be sure to @@ -556,15 +573,15 @@ break; error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); + } else if (de_cn2off(pmp, rablock) >= dep->de_FileSize) { + error = bread(vp, lbn, blsize, NOCRED, &bp); + } else if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { + error = cluster_read(vp, dep->de_FileSize, lbn, blsize, + NOCRED, uio->uio_resid, seqcount, &bp); + } else if (seqcount > 1) { + rasize = blsize; + error = breadn(vp, lbn, + blsize, &rablock, &rasize, 1, NOCRED, &bp); } else { - blsize = pmp->pm_bpcluster; - rablock = lbn + 1; - if (seqcount > 1 && - de_cn2off(pmp, rablock) < dep->de_FileSize) { - rasize = pmp->pm_bpcluster; - error = breadn(vp, lbn, blsize, - &rablock, &rasize, 1, NOCRED, &bp); - } else { - error = bread(vp, lbn, blsize, NOCRED, &bp); - } + error = bread(vp, lbn, blsize, NOCRED, &bp); } if (error) { %%% I rearranged the code to be almost lexically identical with that in ffs_read(). I only tested this on a relatively fast ATA drive. It made little difference. Most writes were clustered to give a block size of 64K and write speed of over 40+MB/s until the disk is nearly full, but reads weren't clustered with or without the patch so the block size remained at the fs block size (4K); the drive handles this block size mediocrely and gave a read speed of 20+MB/sec. (The drive is a WDC 1200JB-00CRA1. This drive has the interesting behaviour of giving almost the same mediocre read speed for all block sizes between 2.5K and 19.5K. A block size 20K gives maximal speed which is about twice as fast as the speed for a block size of 19.5K.) Both reading and writing a 1GB file to/from msdosfs caused noticable buffer resource problems. Accesses to other file systems on the same disk sometimes blocked for many seconds. I have debugging code in getblk(). It reported that a process waited 17 seconds in or near getblk(). The process only stopped waiting because I suspended the process accessing msdosfs. This may be a local bug. Bruce From owner-freebsd-usb@FreeBSD.ORG Mon May 30 10:50:05 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 4422C16A41C for ; Mon, 30 May 2005 10:50:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id E41D443D54 for ; Mon, 30 May 2005 10:50:04 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4UAo4jl027817 for ; Mon, 30 May 2005 10:50:04 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4UAo49r027816; Mon, 30 May 2005 10:50:04 GMT (envelope-from gnats) Date: Mon, 30 May 2005 10:50:04 GMT Message-Id: <200505301050.j4UAo49r027816@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: "Bruce Evans" Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Bruce Evans List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 10:50:05 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: "Bruce Evans" To: Cc: , , Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Mon, 30 May 2005 11:46:06 +0100 On Mon, 30 May 2005, Bruce Evans wrote: > On Sun, 29 May 2005, Dominic Marks wrote: >> I have been experimenting in msdosfs_read and I have managed to come up >> with >> something that works, but I'm sure it is flawed. On large file reads it >> will >> ... >> %% >> Index: msdosfs_vnops.c >> =================================================================== >> RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v >> retrieving revision 1.149.2.1 >> diff -u -r1.149.2.1 msdosfs_vnops.c >> --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 >> +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 >> @@ -565,14 +567,21 @@ >> error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, >> &bp); >> } else { >> blsize = pmp->pm_bpcluster; >> - rablock = lbn + 1; >> - if (seqcount > 1 && >> - de_cn2off(pmp, rablock) < dep->de_FileSize) { >> - rasize = pmp->pm_bpcluster; >> - error = breadn(vp, lbn, blsize, >> - &rablock, &rasize, 1, NOCRED, &bp); >> + /* XXX what is the best value for crsize? */ >> + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : >> blsize * nblks; >> + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { >> + error = cluster_read(vp, dep->de_FileSize, >> lbn, >> + crsize, NOCRED, uio->uio_resid, >> seqcount, &bp); > > crsize should be just the block size (cluster size in msdosfs and > blsize variable here) according to this code in all other file systems. > ... The main problem is that VOP_BMAP() is not fully implemented for msdosfs. msdosfs_bmap() only has a stub which pretends that clustering ins never possible: % /* % * vp - address of vnode file the file % * bn - which cluster we are interested in mapping to a filesystem block number. % * vpp - returns the vnode for the block special file holding the filesystem % * containing the file of interest % * bnp - address of where to return the filesystem relative block number % */ This comment rotted in 1994 when 4.4BSD packed the args into a struct and added the a_runp and a_runb args to support clustering. % static int % msdosfs_bmap(ap) % struct vop_bmap_args /* { % struct vnode *a_vp; % daddr_t a_bn; % struct vnode **a_vpp; % daddr_t *a_bnp; % int *a_runp; % int *a_runb; % } */ *ap; % { % struct denode *dep = VTODE(ap->a_vp); % daddr_t blkno; % int error; % % if (ap->a_vpp != NULL) % *ap->a_vpp = dep->de_devvp; % if (ap->a_bnp == NULL) % return (0); % if (ap->a_runp) { % /* % * Sequential clusters should be counted here. ^^^^^^^^^ % */ % *ap->a_runp = 0; % } % if (ap->a_runb) { % *ap->a_runb = 0; % } % error = pcbmap(dep, ap->a_bn, &blkno, 0, 0); % *ap->a_bnp = blkno; % return (error); % } Here is a cleaned up version of the patch to add (not actually working) clustering to msdosfs_read(). %%% Index: msdosfs_vnops.c =================================================================== RCS file: /home/ncvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v retrieving revision 1.147 diff -u -2 -r1.147 msdosfs_vnops.c --- msdosfs_vnops.c 4 Feb 2004 21:52:53 -0000 1.147 +++ msdosfs_vnops.c 30 May 2005 08:57:02 -0000 @@ -541,5 +555,7 @@ if (uio->uio_offset >= dep->de_FileSize) break; + blsize = pmp->pm_bpcluster; lbn = de_cluster(pmp, uio->uio_offset); + rablock = lbn + 1; /* * If we are operating on a directory file then be sure to @@ -556,15 +573,15 @@ break; error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); + } else if (de_cn2off(pmp, rablock) >= dep->de_FileSize) { + error = bread(vp, lbn, blsize, NOCRED, &bp); + } else if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { + error = cluster_read(vp, dep->de_FileSize, lbn, blsize, + NOCRED, uio->uio_resid, seqcount, &bp); + } else if (seqcount > 1) { + rasize = blsize; + error = breadn(vp, lbn, + blsize, &rablock, &rasize, 1, NOCRED, &bp); } else { - blsize = pmp->pm_bpcluster; - rablock = lbn + 1; - if (seqcount > 1 && - de_cn2off(pmp, rablock) < dep->de_FileSize) { - rasize = pmp->pm_bpcluster; - error = breadn(vp, lbn, blsize, - &rablock, &rasize, 1, NOCRED, &bp); - } else { - error = bread(vp, lbn, blsize, NOCRED, &bp); - } + error = bread(vp, lbn, blsize, NOCRED, &bp); } if (error) { %%% I rearranged the code to be almost lexically identical with that in ffs_read(). I only tested this on a relatively fast ATA drive. It made little difference. Most writes were clustered to give a block size of 64K and write speed of over 40+MB/s until the disk is nearly full, but reads weren't clustered with or without the patch so the block size remained at the fs block size (4K); the drive handles this block size mediocrely and gave a read speed of 20+MB/sec. (The drive is a WDC 1200JB-00CRA1. This drive has the interesting behaviour of giving almost the same mediocre read speed for all block sizes between 2.5K and 19.5K. A block size 20K gives maximal speed which is about twice as fast as the speed for a block size of 19.5K.) Both reading and writing a 1GB file to/from msdosfs caused noticable buffer resource problems. Accesses to other file systems on the same disk sometimes blocked for many seconds. I have debugging code in getblk(). It reported that a process waited 17 seconds in or near getblk(). The process only stopped waiting because I suspended the process accessing msdosfs. This may be a local bug. Bruce _______________________________________________ freebsd-fs@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-fs To unsubscribe, send any mail to "freebsd-fs-unsubscribe@freebsd.org" From owner-freebsd-usb@FreeBSD.ORG Mon May 30 11:02:09 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id F019A16A41C for ; Mon, 30 May 2005 11:02:09 +0000 (GMT) (envelope-from owner-bugmaster@freebsd.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id B765A43D53 for ; Mon, 30 May 2005 11:02:09 +0000 (GMT) (envelope-from owner-bugmaster@freebsd.org) Received: from freefall.freebsd.org (peter@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4UB29aT030175 for ; Mon, 30 May 2005 11:02:09 GMT (envelope-from owner-bugmaster@freebsd.org) Received: (from peter@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4UB28OH030169 for freebsd-usb@freebsd.org; Mon, 30 May 2005 11:02:08 GMT (envelope-from owner-bugmaster@freebsd.org) Date: Mon, 30 May 2005 11:02:08 GMT Message-Id: <200505301102.j4UB28OH030169@freefall.freebsd.org> X-Authentication-Warning: freefall.freebsd.org: peter set sender to owner-bugmaster@freebsd.org using -f From: FreeBSD bugmaster To: freebsd-usb@FreeBSD.org Cc: Subject: Current problem reports assigned to you X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 11:02:10 -0000 Current FreeBSD problem reports Critical problems S Submitted Tracker Resp. Description ------------------------------------------------------------------------------- o [2005/05/26] usb/81524 usb panic: usb_cold_explore: busses to explor 1 problem total. Serious problems S Submitted Tracker Resp. Description ------------------------------------------------------------------------------- o [2002/07/19] kern/40792 usb signals lead to data loss on device ugen o [2002/12/10] kern/46176 usb umass causes kernel panic if device remov o [2002/12/19] i386/46371 usb USB controller cannot be initialized on I f [2003/02/17] kern/48359 usb SiS 5597/8 USB + uscanner breakage f [2003/03/05] kern/48952 usb uscanner0 hangs o [2003/09/26] bin/57255 usb usbd and multi-function devices f [2003/12/11] kern/60131 usb [usb] Page fault on disconnect of USB dev s [2003/12/15] kern/60276 usb [usb] Kernel panic when plugging in USB ( f [2004/01/11] kern/61191 usb [usb] panic: USB vs. Serial problems o [2004/01/20] kern/61627 usb [usb] [patch] New USB printer not support o [2004/01/24] kern/61841 usb [boot] 5.2 Boot freeze if memorybird (USB f [2004/01/30] kern/62088 usb [usb] Logitech Cordless/Optical Mouse not f [2004/01/30] kern/62123 usb [usb] LaCie 160GB USB drive umass: BBB re f [2004/02/23] i386/63251 usb [usb] USB stops working after 2nd APM sus f [2004/03/01] kern/63621 usb [usb] USB MemoryStick Reader stalls/crash f [2004/04/07] kern/65292 usb [panic] random page faults (usb-related?) o [2004/07/13] kern/69006 usb [patch] Apple Cinema Display hangs USB po o [2004/08/30] kern/71155 usb [usb] misbehaving usb-printer hangs proce o [2004/10/30] kern/73307 usb Kernel panics on USB disconnect f [2004/11/18] kern/74088 usb ohci ehci uhub: port disabled on connecti o [2005/01/13] usb/76204 usb panic while using usb attached modem o [2005/01/18] usb/76395 usb USB printer does not work, usbdevs says " o [2005/01/21] usb/76554 usb Panram "yoyo" USB MP3 player causes panic f [2005/01/25] usb/76684 usb Toshiba PDR-M4 camera connected via USB h f [2005/01/26] usb/76727 usb usb printing locks machine f [2005/01/30] usb/76847 usb ukbd panics on boot o [2005/02/06] usb/77184 usb kernel panic on USB device disconnect o [2005/02/09] usb/77294 usb ucom + ulpcom panic o [2005/02/16] usb/77604 usb Sluggish Logitch LX700 USB Mouse o [2005/03/18] usb/78989 usb please add USB keyboard support to instal o [2005/03/22] usb/79140 usb WD Firewire/USB Combo hangs under load on o [2005/03/27] usb/79269 usb USB ohci da0 plug/unplug causes crashes a o [2005/03/27] usb/79287 usb UHCI hang after interrupt transfer o [2005/04/02] usb/79436 usb Panic: ohci_abort_xfer: not in process co o [2005/04/04] usb/79524 usb printing to Minolta PagePro 1[23]xxW via o [2005/04/07] usb/79656 usb [usb] RHSC interrupts lost o [2005/04/09] usb/79722 usb [usb] wrong alignments in ehci.h o [2005/04/17] usb/80040 usb [hang] Use of sound mixer causes system f o [2005/04/22] usb/80260 usb Travan USB tape drive fails to write o [2005/04/26] usb/80361 usb mounting of usb-stick fails o [2005/04/26] usb/80373 usb usb keyboard does not respond o [2005/05/04] usb/80628 usb recent USB MFCs cause panics o [2005/05/06] usb/80685 usb panic in usb_cold_explore() at begining o [2005/05/09] usb/80829 usb possible panic when loading USB-modules o [2005/05/10] usb/80862 usb USB locking issues o [2005/05/20] usb/81308 usb Polling a ugen(4) control endpoint causes 46 problems total. Non-critical problems S Submitted Tracker Resp. Description ------------------------------------------------------------------------------- o [2001/09/30] conf/30929 usb [patch] use usbd to initialize USB ADSL m o [2001/12/09] kern/32652 usb [patch] A new ioctl to uscanner s [2001/12/09] ports/32653 usb Added patches to improve USB scanner supp f [2002/07/24] kern/40948 usb [usb] USB HP CDW8200 does not work o [2002/08/07] kern/41415 usb [usb] [patch] Some USB scanners cannot ta o [2003/02/16] bin/48342 usb [PATCH] usbd dynamic device list. f [2003/03/19] kern/50110 usb [usb] Astra 2100U scanner being detected o [2003/05/08] kern/51958 usb [usb] [patch] update for urio driver o [2003/05/10] kern/52026 usb [usb] feature request: umass driver suppo f [2003/05/19] bin/52432 usb [sysinstall] drivers.flp won't load with o [2003/06/08] kern/53025 usb [PATCH] ugen does not allow O_NONBLOCK fo f [2003/09/19] kern/56999 usb FreeCom USB CD/RW problem on FreeBSD 5.1 f [2003/11/10] i386/59147 usb [usb] USB active extension cable not reco o [2003/11/11] kern/59169 usb [patch] ulpt is missing read operation o [2003/12/15] kern/60248 usb [patch] Problem with USB printer HP Laser o [2004/01/12] bin/61234 usb [usb] [patch] usbhidaction doesn't suppor f [2004/02/13] kern/62788 usb need quirks for Super Talent Flash USB 2. f [2004/03/04] kern/63779 usb [usb] USB-mass storage (USB to IDE Conver o [2004/03/06] kern/63837 usb [patch] USB: hid_is_collection() only loo o [2004/04/11] kern/65436 usb QUIRK: [patch] to add support for PNY Att o [2004/04/19] kern/65769 usb [usb] Call to tcflush(x, TCIFLUSH) stops f [2004/05/11] kern/66547 usb [usb] Palm Tungsten T USB does not initia o [2004/06/27] kern/68412 usb [usb] [patch] QUIRK: Philips KEY013 USB M o [2004/07/06] i386/68719 usb [usb] USB 2.0 mobil rack+ fat32 performan o [2004/08/16] kern/70523 usb [usb] [patch] umct sending/receiving wron o [2004/08/25] kern/70942 usb [usb] Genius Wireless USB mouse: moused d o [2004/09/06] kern/71416 usb [usb] Cryptoflex e-gate USB token (ugen0) o [2004/09/06] kern/71417 usb [usb] Cryptoflex e-gate USB token (ugen0) o [2004/09/07] kern/71455 usb [usb] Slow USB umass performance of 5.3 o [2004/09/11] kern/71605 usb [usb] [patch] umass doesn't recognize mul o [2004/10/05] kern/72344 usb [usb] [patch] QUIRK: Dane-Elec zMate 512 f [2004/10/06] i386/72380 usb [usb] USB does not work [dual Celeron Abi o [2004/10/23] i386/73056 usb [usb] Sun Microsystems Type 6 USB mouse n f [2004/11/02] i386/73421 usb [usb] USB not recgnized/working on Toshib o [2004/11/30] usb/74557 usb imation 500mb usb key can only be written o [2004/12/12] usb/74989 usb (regression) Lost USB support between 5.2 o [2004/12/28] usb/75578 usb [patch] QUIRK: PNY USB flash key o [2005/01/07] usb/75928 usb Cytronix SmartMedia card (SMC) reader has o [2005/01/19] usb/76461 usb disklabel of umass(4)-CAM(4)-da(4) not us o [2005/01/27] usb/76732 usb Mouse problems with USB KVM Switch f [2005/03/03] usb/78371 usb Philips Wearable Audio Player (128) fails o [2005/03/07] usb/78543 usb [patch] Support for Trip-Lite USB 2 Seria o [2005/03/18] usb/78984 usb Creative MUVO umass failure o [2005/04/09] usb/79723 usb [usb] prepare for high speed isochronous o [2005/04/09] usb/79725 usb [patch] [usb] USB device speed is not dou o [2005/04/14] kern/79893 usb New usbdevs/umass quirks derived from Lin o [2005/04/16] usb/80010 usb Add support for the AEI USB to LAN adapte o [2005/04/27] usb/80383 usb [PATCH] Add quirk for uhid to ignore cert o [2005/04/27] usb/80420 usb atapicam stops iPod functionality o [2005/05/08] usb/80773 usb "usbd_get_string()" could have taken a le o [2005/05/08] usb/80774 usb have "usbd_find_desc" in line with the ot o [2005/05/08] usb/80776 usb UDAV device driver shouldn't use usb_add_ o [2005/05/08] usb/80777 usb usb_rem_task() should wait for callback t o [2005/05/10] usb/80854 usb suggestion for new iface-no-probe mechani o [2005/05/12] usb/80935 usb uvisor.c is not work with CLIE TH55. o [2005/05/15] usb/81073 usb [patch] fix umass NO_GETMAXLUN quirk o [2005/05/18] usb/81191 usb Support for Curitel HX-550C USB modem to o [2005/05/29] usb/81621 usb external hd hangs under load on ehci 58 problems total. From owner-freebsd-usb@FreeBSD.ORG Mon May 30 11:40:02 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id D582D16A41C for ; Mon, 30 May 2005 11:40:02 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 51F0443D5F for ; Mon, 30 May 2005 11:40:02 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4UBe2u1038085 for ; Mon, 30 May 2005 11:40:02 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4UBe2WE038084; Mon, 30 May 2005 11:40:02 GMT (envelope-from gnats) Resent-Date: Mon, 30 May 2005 11:40:02 GMT Resent-Message-Id: <200505301140.j4UBe2WE038084@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-usb@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Jiri Popek Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id F36AA16A41C for ; Mon, 30 May 2005 11:32:51 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (www.freebsd.org [216.136.204.117]) by mx1.FreeBSD.org (Postfix) with ESMTP id CF5EF43D4C for ; Mon, 30 May 2005 11:32:51 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.13.1/8.13.1) with ESMTP id j4UBWpjq098606 for ; Mon, 30 May 2005 11:32:51 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.13.1/8.13.1/Submit) id j4UBWpO2098605; Mon, 30 May 2005 11:32:51 GMT (envelope-from nobody) Message-Id: <200505301132.j4UBWpO2098605@www.freebsd.org> Date: Mon, 30 May 2005 11:32:51 GMT From: Jiri Popek To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-2.3 Cc: Subject: usb/81656: umass problem with Minolta DiMage S414 Digital Camera X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 11:40:03 -0000 >Number: 81656 >Category: usb >Synopsis: umass problem with Minolta DiMage S414 Digital Camera >Confidential: no >Severity: non-critical >Priority: medium >Responsible: freebsd-usb >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Mon May 30 11:40:01 GMT 2005 >Closed-Date: >Last-Modified: >Originator: Jiri Popek >Release: 5.4-RELEASE >Organization: >Environment: FreeBSD jardous.vsb.cz 5.4-RELEASE FreeBSD 5.4-RELEASE #0: Sun May 8 10:21:06 UTC 2005 >Description: dmesg reports: umass0: MINOLTA DIMAGE CAMERA DIMAGE CAMERA, rev 1.00/0.01, addr 3 umass0: Get Max Lun not supported (IOERROR) da0 at umass-sim0 bus 0 target 0 lun 0 da0: Removable Direct Access SCSI-0 device da0: 1.000MB/s transfers da0: 122MB (250080 512 byte sectors: 64H 32S/T 122C) umass0: Invalid CSW: sig 0x53000000 should be 0x53425355 (da0:umass-sim0:0:0:0): Synchronize cache failed, status == 0x4, scsi status == 0x0 umass0: Invalid CSW: sig 0x53000000 should be 0x53425355 (da0:umass-sim0:0:0:0): Synchronize cache failed, status == 0x4, scsi status == 0x0 >How-To-Repeat: Every time when trying to plug camera. >Fix: >Release-Note: >Audit-Trail: >Unformatted: From owner-freebsd-usb@FreeBSD.ORG Mon May 30 15:10:28 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 92FC716A5DC for ; Mon, 30 May 2005 15:10:25 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 2F9D743D5D for ; Mon, 30 May 2005 15:10:11 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4UFABtJ065943 for ; Mon, 30 May 2005 15:10:11 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4UFABeL065942; Mon, 30 May 2005 15:10:11 GMT (envelope-from gnats) Date: Mon, 30 May 2005 15:10:11 GMT Message-Id: <200505301510.j4UFABeL065942@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Dominic Marks Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Dominic Marks List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 15:10:28 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: Dominic Marks To: Bruce Evans Cc: freebsd-fs@freebsd.org, freebsd-gnats-submit@freebsd.org, banhalmi@field.hu Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Mon, 30 May 2005 16:09:11 +0100 On Monday 30 May 2005 11:11, Bruce Evans wrote: > On Mon, 30 May 2005, Bruce Evans wrote: > > On Sun, 29 May 2005, Dominic Marks wrote: > >> I have been experimenting in msdosfs_read and I have managed to come up > >> with > >> something that works, but I'm sure it is flawed. On large file reads it > >> will > >> ... > >> %% > >> Index: msdosfs_vnops.c > >> =================================================================== > >> RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > >> retrieving revision 1.149.2.1 > >> diff -u -r1.149.2.1 msdosfs_vnops.c > >> --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 > >> +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 > >> @@ -565,14 +567,21 @@ > >> error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, > >> &bp); > >> } else { > >> blsize = pmp->pm_bpcluster; > >> - rablock = lbn + 1; > >> - if (seqcount > 1 && > >> - de_cn2off(pmp, rablock) < dep->de_FileSize) { > >> - rasize = pmp->pm_bpcluster; > >> - error = breadn(vp, lbn, blsize, > >> - &rablock, &rasize, 1, NOCRED, &bp); > >> + /* XXX what is the best value for crsize? */ > >> + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : > >> blsize * nblks; > >> + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { > >> + error = cluster_read(vp, dep->de_FileSize, > >> lbn, > >> + crsize, NOCRED, uio->uio_resid, > >> seqcount, &bp); > > > > crsize should be just the block size (cluster size in msdosfs and > > blsize variable here) according to this code in all other file systems. > > ... > > The main problem is that VOP_BMAP() is not fully implemented for msdosfs. > msdosfs_bmap() only has a stub which pretends that clustering ins never > possible: > > % /* > % * vp - address of vnode file the file > % * bn - which cluster we are interested in mapping to a filesystem block > number. % * vpp - returns the vnode for the block special file holding the > filesystem % * containing the file of interest > % * bnp - address of where to return the filesystem relative block number > % */ > > This comment rotted in 1994 when 4.4BSD packed the args into a struct > and added the a_runp and a_runb args to support clustering. > > % static int > % msdosfs_bmap(ap) > % struct vop_bmap_args /* { > % struct vnode *a_vp; > % daddr_t a_bn; > % struct vnode **a_vpp; > % daddr_t *a_bnp; > % int *a_runp; > % int *a_runb; > % } */ *ap; > % { > % struct denode *dep = VTODE(ap->a_vp); > % daddr_t blkno; > % int error; > % > % if (ap->a_vpp != NULL) > % *ap->a_vpp = dep->de_devvp; > % if (ap->a_bnp == NULL) > % return (0); > % if (ap->a_runp) { > % /* > % * Sequential clusters should be counted here. > ^^^^^^^^^ > % */ > % *ap->a_runp = 0; > % } > % if (ap->a_runb) { > % *ap->a_runb = 0; > % } > % error = pcbmap(dep, ap->a_bn, &blkno, 0, 0); > % *ap->a_bnp = blkno; > % return (error); > % } If I understand what is supposed to be done here (I looked at cd9660 but I don't know if the rules are different from msdos), a_runp should be set to the extent of contiguous blocks from the current position within the same region? I put some debugging into msdosfs_bmap and here it is copied: (fsz is dep->de_FileSize) msdosfs_bmap: fsz 81047 blkno 6374316 lblkno 5 msdosfs_bmap: fsz 81047 blkno 6374324 lblkno 6 msdosfs_bmap: fsz 81047 blkno 6374332 lblkno 7 msdosfs_bmap: fsz 81047 blkno 6374340 lblkno 8 msdosfs_bmap: fsz 81047 blkno 6374348 lblkno 9 msdosfs_bmap: fsz 81047 blkno 6374356 lblkno 10 msdosfs_bmap: fsz 81047 blkno 6374364 lblkno 11 msdosfs_bmap: fsz 81047 blkno 6374372 lblkno 12 # A1 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 13 # A2 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 14 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 15 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 16 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 17 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 18 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 19 I should compute the position of the boundary illustrated in A1 I should set that to the read ahead value, until setting a new value at A2, perhaps this should only be done for particularly large files? I will look at the other _bmap routines to see what they do. > Here is a cleaned up version of the patch to add (not actually working) > clustering to msdosfs_read(). > > %%% > Index: msdosfs_vnops.c > =================================================================== > RCS file: /home/ncvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > retrieving revision 1.147 > diff -u -2 -r1.147 msdosfs_vnops.c > --- msdosfs_vnops.c 4 Feb 2004 21:52:53 -0000 1.147 > +++ msdosfs_vnops.c 30 May 2005 08:57:02 -0000 > @@ -541,5 +555,7 @@ > if (uio->uio_offset >= dep->de_FileSize) > break; > + blsize = pmp->pm_bpcluster; > lbn = de_cluster(pmp, uio->uio_offset); > + rablock = lbn + 1; > /* > * If we are operating on a directory file then be sure to > @@ -556,15 +573,15 @@ > break; > error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); > + } else if (de_cn2off(pmp, rablock) >= dep->de_FileSize) { > + error = bread(vp, lbn, blsize, NOCRED, &bp); > + } else if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { > + error = cluster_read(vp, dep->de_FileSize, lbn, blsize, > + NOCRED, uio->uio_resid, seqcount, &bp); > + } else if (seqcount > 1) { > + rasize = blsize; > + error = breadn(vp, lbn, > + blsize, &rablock, &rasize, 1, NOCRED, &bp); > } else { > - blsize = pmp->pm_bpcluster; > - rablock = lbn + 1; > - if (seqcount > 1 && > - de_cn2off(pmp, rablock) < dep->de_FileSize) { > - rasize = pmp->pm_bpcluster; > - error = breadn(vp, lbn, blsize, > - &rablock, &rasize, 1, NOCRED, &bp); > - } else { > - error = bread(vp, lbn, blsize, NOCRED, &bp); > - } > + error = bread(vp, lbn, blsize, NOCRED, &bp); > } > if (error) { > %%% > > I rearranged the code to be almost lexically identical with that in > ffs_read(). Thanks, I will use this as a basis for any other things I try. > I only tested this on a relatively fast ATA drive. It made little > difference. Most writes were clustered to give a block size of 64K > and write speed of over 40+MB/s until the disk is nearly full, but > reads weren't clustered with or without the patch so the block size > remained at the fs block size (4K); the drive handles this block size > mediocrely and gave a read speed of 20+MB/sec. (The drive is a WDC > 1200JB-00CRA1. This drive has the interesting behaviour of giving > almost the same mediocre read speed for all block sizes between 2.5K > and 19.5K. A block size 20K gives maximal speed which is about twice > as fast as the speed for a block size of 19.5K.) I am still confused as to how reading blsize * 16 actually improved the transfer rate after a long period of making it worse. Perhaps it is related to the buffer resource problem you describe below. > Both reading and writing a 1GB file to/from msdosfs caused noticable > buffer resource problems. Accesses to other file systems on the same > disk sometimes blocked for many seconds. I have debugging code in > getblk(). It reported that a process waited 17 seconds in or near > getblk(). The process only stopped waiting because I suspended the > process accessing msdosfs. This may be a local bug. I'll look for buffer resource statistics in the system tools and measure those. There are no obvious signs, to me, that the systems are in any specific difficulties while running the transfers. > Bruce Thanks a lot for the answers and code, -- Dominic GoodforBusiness.co.uk I.T. Services for SMEs in the UK. From owner-freebsd-usb@FreeBSD.ORG Mon May 30 16:10:06 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id EFFEE16A41C for ; Mon, 30 May 2005 16:10:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id B8E6C43D54 for ; Mon, 30 May 2005 16:10:05 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4UGA50c072889 for ; Mon, 30 May 2005 16:10:05 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4UGA5cD072888; Mon, 30 May 2005 16:10:05 GMT (envelope-from gnats) Date: Mon, 30 May 2005 16:10:05 GMT Message-Id: <200505301610.j4UGA5cD072888@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: "Dominic Marks" Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Dominic Marks List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 May 2005 16:10:06 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: "Dominic Marks" To: Cc: , , Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Mon, 30 May 2005 17:00:54 +0100 On Monday 30 May 2005 11:11, Bruce Evans wrote: > On Mon, 30 May 2005, Bruce Evans wrote: > > On Sun, 29 May 2005, Dominic Marks wrote: > >> I have been experimenting in msdosfs_read and I have managed to come up > >> with > >> something that works, but I'm sure it is flawed. On large file reads it > >> will > >> ... > >> %% > >> Index: msdosfs_vnops.c > >> =================================================================== > >> RCS file: /usr/cvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > >> retrieving revision 1.149.2.1 > >> diff -u -r1.149.2.1 msdosfs_vnops.c > >> --- msdosfs_vnops.c 31 Jan 2005 23:25:56 -0000 1.149.2.1 > >> +++ msdosfs_vnops.c 29 May 2005 14:10:18 -0000 > >> @@ -565,14 +567,21 @@ > >> error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, > >> &bp); > >> } else { > >> blsize = pmp->pm_bpcluster; > >> - rablock = lbn + 1; > >> - if (seqcount > 1 && > >> - de_cn2off(pmp, rablock) < dep->de_FileSize) { > >> - rasize = pmp->pm_bpcluster; > >> - error = breadn(vp, lbn, blsize, > >> - &rablock, &rasize, 1, NOCRED, &bp); > >> + /* XXX what is the best value for crsize? */ > >> + crsize = blsize * nblks > MAXBSIZE ? MAXBSIZE : > >> blsize * nblks; > >> + if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { > >> + error = cluster_read(vp, dep->de_FileSize, > >> lbn, > >> + crsize, NOCRED, uio->uio_resid, > >> seqcount, &bp); > > > > crsize should be just the block size (cluster size in msdosfs and > > blsize variable here) according to this code in all other file systems. > > ... > > The main problem is that VOP_BMAP() is not fully implemented for msdosfs. > msdosfs_bmap() only has a stub which pretends that clustering ins never > possible: > > % /* > % * vp - address of vnode file the file > % * bn - which cluster we are interested in mapping to a filesystem block > number. % * vpp - returns the vnode for the block special file holding the > filesystem % * containing the file of interest > % * bnp - address of where to return the filesystem relative block number > % */ > > This comment rotted in 1994 when 4.4BSD packed the args into a struct > and added the a_runp and a_runb args to support clustering. > > % static int > % msdosfs_bmap(ap) > % struct vop_bmap_args /* { > % struct vnode *a_vp; > % daddr_t a_bn; > % struct vnode **a_vpp; > % daddr_t *a_bnp; > % int *a_runp; > % int *a_runb; > % } */ *ap; > % { > % struct denode *dep = VTODE(ap->a_vp); > % daddr_t blkno; > % int error; > % > % if (ap->a_vpp != NULL) > % *ap->a_vpp = dep->de_devvp; > % if (ap->a_bnp == NULL) > % return (0); > % if (ap->a_runp) { > % /* > % * Sequential clusters should be counted here. > ^^^^^^^^^ > % */ > % *ap->a_runp = 0; > % } > % if (ap->a_runb) { > % *ap->a_runb = 0; > % } > % error = pcbmap(dep, ap->a_bn, &blkno, 0, 0); > % *ap->a_bnp = blkno; > % return (error); > % } If I understand what is supposed to be done here (I looked at cd9660 but I don't know if the rules are different from msdos), a_runp should be set to the extent of contiguous blocks from the current position within the same region? I put some debugging into msdosfs_bmap and here it is copied: (fsz is dep->de_FileSize) msdosfs_bmap: fsz 81047 blkno 6374316 lblkno 5 msdosfs_bmap: fsz 81047 blkno 6374324 lblkno 6 msdosfs_bmap: fsz 81047 blkno 6374332 lblkno 7 msdosfs_bmap: fsz 81047 blkno 6374340 lblkno 8 msdosfs_bmap: fsz 81047 blkno 6374348 lblkno 9 msdosfs_bmap: fsz 81047 blkno 6374356 lblkno 10 msdosfs_bmap: fsz 81047 blkno 6374364 lblkno 11 msdosfs_bmap: fsz 81047 blkno 6374372 lblkno 12 # A1 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 13 # A2 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 14 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 15 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 16 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 17 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 18 msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 19 I should compute the position of the boundary illustrated in A1 I should set that to the read ahead value, until setting a new value at A2, perhaps this should only be done for particularly large files? I will look at the other _bmap routines to see what they do. > Here is a cleaned up version of the patch to add (not actually working) > clustering to msdosfs_read(). > > %%% > Index: msdosfs_vnops.c > =================================================================== > RCS file: /home/ncvs/src/sys/fs/msdosfs/msdosfs_vnops.c,v > retrieving revision 1.147 > diff -u -2 -r1.147 msdosfs_vnops.c > --- msdosfs_vnops.c 4 Feb 2004 21:52:53 -0000 1.147 > +++ msdosfs_vnops.c 30 May 2005 08:57:02 -0000 > @@ -541,5 +555,7 @@ > if (uio->uio_offset >= dep->de_FileSize) > break; > + blsize = pmp->pm_bpcluster; > lbn = de_cluster(pmp, uio->uio_offset); > + rablock = lbn + 1; > /* > * If we are operating on a directory file then be sure to > @@ -556,15 +573,15 @@ > break; > error = bread(pmp->pm_devvp, lbn, blsize, NOCRED, &bp); > + } else if (de_cn2off(pmp, rablock) >= dep->de_FileSize) { > + error = bread(vp, lbn, blsize, NOCRED, &bp); > + } else if ((vp->v_mount->mnt_flag & MNT_NOCLUSTERR) == 0) { > + error = cluster_read(vp, dep->de_FileSize, lbn, blsize, > + NOCRED, uio->uio_resid, seqcount, &bp); > + } else if (seqcount > 1) { > + rasize = blsize; > + error = breadn(vp, lbn, > + blsize, &rablock, &rasize, 1, NOCRED, &bp); > } else { > - blsize = pmp->pm_bpcluster; > - rablock = lbn + 1; > - if (seqcount > 1 && > - de_cn2off(pmp, rablock) < dep->de_FileSize) { > - rasize = pmp->pm_bpcluster; > - error = breadn(vp, lbn, blsize, > - &rablock, &rasize, 1, NOCRED, &bp); > - } else { > - error = bread(vp, lbn, blsize, NOCRED, &bp); > - } > + error = bread(vp, lbn, blsize, NOCRED, &bp); > } > if (error) { > %%% > > I rearranged the code to be almost lexically identical with that in > ffs_read(). Thanks, I will use this as a basis for any other things I try. > I only tested this on a relatively fast ATA drive. It made little > difference. Most writes were clustered to give a block size of 64K > and write speed of over 40+MB/s until the disk is nearly full, but > reads weren't clustered with or without the patch so the block size > remained at the fs block size (4K); the drive handles this block size > mediocrely and gave a read speed of 20+MB/sec. (The drive is a WDC > 1200JB-00CRA1. This drive has the interesting behaviour of giving > almost the same mediocre read speed for all block sizes between 2.5K > and 19.5K. A block size 20K gives maximal speed which is about twice > as fast as the speed for a block size of 19.5K.) I am still confused as to how reading blsize * 16 actually improved the transfer rate after a long period of making it worse. Perhaps it is related to the buffer resource problem you describe below. > Both reading and writing a 1GB file to/from msdosfs caused noticable > buffer resource problems. Accesses to other file systems on the same > disk sometimes blocked for many seconds. I have debugging code in > getblk(). It reported that a process waited 17 seconds in or near > getblk(). The process only stopped waiting because I suspended the > process accessing msdosfs. This may be a local bug. I'll look for buffer resource statistics in the system tools and measure those. There are no obvious signs, to me, that the systems are in any specific difficulties while running the transfers. > Bruce Thanks a lot for the answers and code, -- Dominic GoodforBusiness.co.uk I.T. Services for SMEs in the UK. _______________________________________________ freebsd-fs@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-fs To unsubscribe, send any mail to "freebsd-fs-unsubscribe@freebsd.org" From owner-freebsd-usb@FreeBSD.ORG Tue May 31 03:10:08 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id E5DE616A41C for ; Tue, 31 May 2005 03:10:07 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id BE93143D1D for ; Tue, 31 May 2005 03:10:07 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4V3A77I055211 for ; Tue, 31 May 2005 03:10:07 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4V3A7FO055208; Tue, 31 May 2005 03:10:07 GMT (envelope-from gnats) Date: Tue, 31 May 2005 03:10:07 GMT Message-Id: <200505310310.j4V3A7FO055208@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: Bruce Evans Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Bruce Evans List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 31 May 2005 03:10:08 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: Bruce Evans To: Dominic Marks Cc: freebsd-fs@FreeBSD.org, freebsd-gnats-submit@FreeBSD.org, banhalmi@field.hu Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Tue, 31 May 2005 13:05:26 +1000 (EST) On Mon, 30 May 2005, Dominic Marks wrote: > On Monday 30 May 2005 11:11, Bruce Evans wrote: >> The main problem is that VOP_BMAP() is not fully implemented for msdosfs. >> msdosfs_bmap() only has a stub which pretends that clustering ins never >> possible: > > If I understand what is supposed to be done here (I looked at cd9660 but > I don't know if the rules are different from msdos), a_runp should be set > to the extent of contiguous blocks from the current position within the > same region? I put some debugging into msdosfs_bmap and here it is copied: cd9660 is deceptively simple here because (I think) it allocates files in perfectly contiguous extents. msdosfs, ffs^ufs and ext2fs have to do considerable work to map even a single block. The details are in pcbmap() for msdosfs. (The name of this function dates from when msdosfs was named pcfs.) I think msdosfs_bmap() just needs to call this function for each block following the start block until a discontiguity is hit or a limit (*) is reached. ufs and ext2fs have an optimized and obfucsated version of this, with multiple blocks looked up at once and the single-block lookup implemented as a multiple-block lookup with a count of 1. I doubt that this optimization is significant even for ufs, at least now that CPUs are 10 to 100 times as fast relative to I/O as when it was implemented. However it is easier to optimize for msdosfs since there are no indirect blocks. All of cd9660, ufs and ext2fs have a whole file *_bmap.c for bmapping. ext2_bmaparray() is simplest, but bmapping in ext2fs and ufs is so similar that misspelling ext2_getlbns() as ufs_getlbns() in 1 caller is harmless. (*) The correct limit is mnt_iosize_max bytes. cd9660 uses the wrong limit of MAXBSIZE. > (fsz is dep->de_FileSize) > > msdosfs_bmap: fsz 81047 blkno 6374316 lblkno 5 > ... > msdosfs_bmap: fsz 81047 blkno 6374364 lblkno 11 > msdosfs_bmap: fsz 81047 blkno 6374372 lblkno 12 # A1 > msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 13 # A2 > msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 14 > ... > > I should compute the position of the boundary illustrated in A1 I should set > that to the read ahead value, until setting a new value at A2, perhaps this > should only be done for particularly large files? I will look at the other > _bmap routines to see what they do. Better to do it for all files. For small files there are just fewer blocks to check for contiguity. > I am still confused as to how reading blsize * 16 actually improved > the transfer rate after a long period of making it worse. Perhaps it > is related to the buffer resource problem you describe below. Could be. The buffer cache layer doesn't handle either overlapping buffers or variant buffer sizes very well. Buffer sizes of (blsize * 16) mixed with buffer sizes of blsize for msdosfs and 16K for ffs may excercise both of these. Bruce From owner-freebsd-usb@FreeBSD.ORG Tue May 31 04:40:06 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id BE40016A41C for ; Tue, 31 May 2005 04:40:06 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 9500543D48 for ; Tue, 31 May 2005 04:40:06 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j4V4e6gh089265 for ; Tue, 31 May 2005 04:40:06 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j4V4e6Vt089262; Tue, 31 May 2005 04:40:06 GMT (envelope-from gnats) Date: Tue, 31 May 2005 04:40:06 GMT Message-Id: <200505310440.j4V4e6Vt089262@freefall.freebsd.org> To: freebsd-usb@FreeBSD.org From: "Bruce Evans" Cc: Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: Bruce Evans List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 31 May 2005 04:40:07 -0000 The following reply was made to PR i386/68719; it has been noted by GNATS. From: "Bruce Evans" To: Cc: , , Subject: Re: i386/68719: [usb] USB 2.0 mobil rack+ fat32 performance problem Date: Tue, 31 May 2005 05:30:20 +0100 On Mon, 30 May 2005, Dominic Marks wrote: > On Monday 30 May 2005 11:11, Bruce Evans wrote: >> The main problem is that VOP_BMAP() is not fully implemented for msdosfs. >> msdosfs_bmap() only has a stub which pretends that clustering ins never >> possible: > > If I understand what is supposed to be done here (I looked at cd9660 but > I don't know if the rules are different from msdos), a_runp should be set > to the extent of contiguous blocks from the current position within the > same region? I put some debugging into msdosfs_bmap and here it is copied: cd9660 is deceptively simple here because (I think) it allocates files in perfectly contiguous extents. msdosfs, ffs^ufs and ext2fs have to do considerable work to map even a single block. The details are in pcbmap() for msdosfs. (The name of this function dates from when msdosfs was named pcfs.) I think msdosfs_bmap() just needs to call this function for each block following the start block until a discontiguity is hit or a limit (*) is reached. ufs and ext2fs have an optimized and obfucsated version of this, with multiple blocks looked up at once and the single-block lookup implemented as a multiple-block lookup with a count of 1. I doubt that this optimization is significant even for ufs, at least now that CPUs are 10 to 100 times as fast relative to I/O as when it was implemented. However it is easier to optimize for msdosfs since there are no indirect blocks. All of cd9660, ufs and ext2fs have a whole file *_bmap.c for bmapping. ext2_bmaparray() is simplest, but bmapping in ext2fs and ufs is so similar that misspelling ext2_getlbns() as ufs_getlbns() in 1 caller is harmless. (*) The correct limit is mnt_iosize_max bytes. cd9660 uses the wrong limit of MAXBSIZE. > (fsz is dep->de_FileSize) > > msdosfs_bmap: fsz 81047 blkno 6374316 lblkno 5 > ... > msdosfs_bmap: fsz 81047 blkno 6374364 lblkno 11 > msdosfs_bmap: fsz 81047 blkno 6374372 lblkno 12 # A1 > msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 13 # A2 > msdosfs_bmap: fsz 81047 blkno 13146156 lblkno 14 > ... > > I should compute the position of the boundary illustrated in A1 I should set > that to the read ahead value, until setting a new value at A2, perhaps this > should only be done for particularly large files? I will look at the other > _bmap routines to see what they do. Better to do it for all files. For small files there are just fewer blocks to check for contiguity. > I am still confused as to how reading blsize * 16 actually improved > the transfer rate after a long period of making it worse. Perhaps it > is related to the buffer resource problem you describe below. Could be. The buffer cache layer doesn't handle either overlapping buffers or variant buffer sizes very well. Buffer sizes of (blsize * 16) mixed with buffer sizes of blsize for msdosfs and 16K for ffs may excercise both of these. Bruce _______________________________________________ freebsd-fs@freebsd.org mailing list http://lists.freebsd.org/mailman/listinfo/freebsd-fs To unsubscribe, send any mail to "freebsd-fs-unsubscribe@freebsd.org" From owner-freebsd-usb@FreeBSD.ORG Wed Jun 1 19:10:02 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id B930516A41C for ; Wed, 1 Jun 2005 19:10:02 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 4DE3943D48 for ; Wed, 1 Jun 2005 19:10:02 +0000 (GMT) (envelope-from gnats@FreeBSD.org) Received: from freefall.freebsd.org (gnats@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j51JA2Ag020776 for ; Wed, 1 Jun 2005 19:10:02 GMT (envelope-from gnats@freefall.freebsd.org) Received: (from gnats@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j51JA2R8020775; Wed, 1 Jun 2005 19:10:02 GMT (envelope-from gnats) Resent-Date: Wed, 1 Jun 2005 19:10:02 GMT Resent-Message-Id: <200506011910.j51JA2R8020775@freefall.freebsd.org> Resent-From: FreeBSD-gnats-submit@FreeBSD.org (GNATS Filer) Resent-To: freebsd-usb@FreeBSD.org Resent-Reply-To: FreeBSD-gnats-submit@FreeBSD.org, Toomas Aas Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 3F6D216A41F for ; Wed, 1 Jun 2005 19:06:59 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (www.freebsd.org [216.136.204.117]) by mx1.FreeBSD.org (Postfix) with ESMTP id E5E9743D1D for ; Wed, 1 Jun 2005 19:06:58 +0000 (GMT) (envelope-from nobody@FreeBSD.org) Received: from www.freebsd.org (localhost [127.0.0.1]) by www.freebsd.org (8.13.1/8.13.1) with ESMTP id j51J6wVL094768 for ; Wed, 1 Jun 2005 19:06:58 GMT (envelope-from nobody@www.freebsd.org) Received: (from nobody@localhost) by www.freebsd.org (8.13.1/8.13.1/Submit) id j51J6wOU094767; Wed, 1 Jun 2005 19:06:58 GMT (envelope-from nobody) Message-Id: <200506011906.j51J6wOU094767@www.freebsd.org> Date: Wed, 1 Jun 2005 19:06:58 GMT From: Toomas Aas To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-2.3 Cc: Subject: usb/81774: 2nd generation iPod mini cannot be mounted over USB X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 01 Jun 2005 19:10:03 -0000 >Number: 81774 >Category: usb >Synopsis: 2nd generation iPod mini cannot be mounted over USB >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-usb >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Wed Jun 01 19:10:01 GMT 2005 >Closed-Date: >Last-Modified: >Originator: Toomas Aas >Release: 5.4-STABLE updated 20050531 >Organization: >Environment: FreeBSD premium.kodu.lan 5.4-STABLE FreeBSD 5.4-STABLE #2: Wed Jun 1 19:45:36 EEST 2005 toomas@premium.kodu.lan:/usr/obj/usr/src/sys/PREMIUM i386 >Description: My hardware: i386 machine based on ASUS P3B-F motherboard. USB 2.0 add-in card recognized in dmesg as follows: usb1: on uhci1 usb1: USB revision 1.0 usbd_get_string: getting lang failed, using 0 uhub1: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub1: 2 ports with 2 removable, self powered uhci2: port 0xb000-0xb01f irq 9 at device 14.1 on pci0 usb2: on uhci2 usb2: USB revision 1.0 usbd_get_string: getting lang failed, using 0 uhub2: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1 uhub2: 2 ports with 2 removable, self powered ehci0: mem 0xe0800000-0xe08000ff irq 11 at device 14.2 on pci0 usb3: EHCI version 0.95 usb3: companion controllers, 2 ports each: usb1 usb2 usb3: on ehci0 usb3: USB revision 2.0 uhub3: VIA EHCI root hub, class 9/0, rev 2.00/1.00, addr 1 uhub3: 4 ports with 4 removable, self powered 2nd generation iPod mini (identified in LCD "About" menu as version 1.3) My kernel is configured to support USB mass storage devices and I have successfully used two different USB flash disks with it. 'options USB_DEBUG' has been added to the kernel and following sysctl options set: hw.usb.ehci.debug=6 hw.usb.umass.debug=6 When connecting the iPod mini to USB port using the supplied iPod dock connector to USB cable, the umass device entry appears in dmesg, but the entry for da device does not appear. Hence there's nothing to mount. The same PC, when booted with Knoppix 3.7 CD, can successfully mount the iPod as /dev/sda2. dmesg output: ehci_pcd: change=0x04 ehci_pcd_able: on=0 ehci_root_ctrl_start: type=0xa3 request=00 ehci_root_ctrl_start: type=0xa3 request=00 ehci_root_ctrl_start: type=0x23 request=01 ehci_root_ctrl_start: type=0x23 request=03 ehci_root_ctrl_start: reset port 2 ehci after reset, status=0x00001005 ehci port 2 reset, status = 0x00001005 ehci_root_ctrl_start: type=0xa3 request=00 ehci_root_ctrl_start: type=0x23 request=01 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x80220d80: toggle=1 bytes=0x22 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=34, actlen=34, cerr=3, status=0x8c00 ehci_ctrl_done: length=34 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x06, wValue=0x0200, wIndex=0x0000 len=9, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=9 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=9 curlen=9 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x80090d80: toggle=1 bytes=0x9 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=9, actlen=9, cerr=3, status=0x8c00 ehci_ctrl_done: length=9 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x06, wValue=0x0200, wIndex=0x0000 len=32, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=32 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=32 curlen=32 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f60<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x80200d80: toggle=1 bytes=0x20 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=32, actlen=32, cerr=3, status=0x8c00 ehci_ctrl_done: length=32 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x00, wValue=0x0000, wIndex=0x0000 len=2, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=2 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=2 curlen=2 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4ea0<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x80020d80: toggle=1 bytes=0x2 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=2, actlen=1, cerr=3, status=0x8c00 usbd_transfer_cb: short transfer 1<2 ehci_ctrl_done: length=1 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x00, request=0x09, wValue=0x0001, wIndex=0x0000 len=0, addr=2, endpt=0 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x00000001 altnext=0x00000001 status=0x80008d80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=0, actlen=0, cerr=3, status=0x8d00 ehci_ctrl_done: length=0 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x06, wValue=0x0301, wIndex=0x0409 len=2, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=2 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=2 curlen=2 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f60<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008d00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=1 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x80020d80: toggle=1 bytes=0x2 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=2, actlen=2, cerr=3, status=0x8c00 ehci_ctrl_done: length=2 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x06, wValue=0x0301, wIndex=0x0409 len=12, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=12 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=12 curlen=12 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x800c0d80: toggle=1 bytes=0xc ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=12, actlen=12, cerr=3, status=0x8c00 ehci_ctrl_done: length=12 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x06, wValue=0x0302, wIndex=0x0409 len=2, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=2 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=2 curlen=2 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4ea0<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x80020d80: toggle=1 bytes=0x2 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=2, actlen=2, cerr=3, status=0x8c00 ehci_ctrl_done: length=2 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0x80, request=0x06, wValue=0x0302, wIndex=0x0409 len=20, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=20 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=20 curlen=20 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f60<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x80140d80: toggle=1 bytes=0x14 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=20, actlen=20, cerr=3, status=0x8c00 ehci_ctrl_done: length=20 ehci_idone: ex=0xc16e0b00 done umass0: Apple iPod mini, rev 2.00/0.01, addr 2 umass0: SCSI over Bulk-Only; quirks = 0x0000 ehci_open: pipe=0xc1bd7080, addr=2, endpt=1 (1) ehci_add_qh: QH(0xc172dd80) at 0x00261d80: link=0x00261de2 endp=0x82006102 addr=0x02 inact=0 endpt=1 eps=2 dtc=1 hrecl=0 mpl=0x200 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x00000001 Overlay qTD: next=0x00000001 altnext=0x00000001 status=0x00000000: toggle=0 bytes=0x0 ioc=0 c_page=0x0 cerr=0 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_device_clear_toggle: epipe=0xc1bd7080 status=0x0 usbd_dump_pipe: pipe=0xc1bd7080 usbd_dump_iface: iface=0xc18264e0 device=0xc1bd7580 idesc=0xc18267a9 index=0 altindex=0 priv=0 usbd_dump_device: dev=0xc1bd7580 bus=0xc16b3000 default_pipe=0xc1bd7300 address=2 config=1 depth=1 speed=3 self_powered=0 power=500 langid=1033 usbd_dump_endpoint: endp=0xc1606648 edesc=0xc18267b9 refcnt=1 bEndpointAddress=0x01 (usbd_dump_pipe:) refcnt=1 running=0 aborting=0 intrxfer=0, repeat=0, interval=-1 ehci_device_request: type=0x02, request=0x01, wValue=0x0000, wIndex=0x0001 len=0, addr=2, endpt=0 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x80008d80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_pcd_able: on=1 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=0, actlen=0, cerr=3, status=0x8d00 ehci_ctrl_done: length=0 ehci_idone: ex=0xc16e0b00 done ehci_open: pipe=0xc1bd7180, addr=2, endpt=130 (1) ehci_add_qh: QH(0xc172dd20) at 0x00261d20: link=0x00261d82 endp=0x82006202 addr=0x02 inact=0 endpt=2 eps=2 dtc=1 hrecl=0 mpl=0x200 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x00000001 Overlay qTD: next=0x00000001 altnext=0x00000001 status=0x00000000: toggle=0 bytes=0x0 ioc=0 c_page=0x0 cerr=0 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_device_clear_toggle: epipe=0xc1bd7180 status=0x0 usbd_dump_pipe: pipe=0xc1bd7180 usbd_dump_iface: iface=0xc18264e0 device=0xc1bd7580 idesc=0xc18267a9 index=0 altindex=0 priv=0 usbd_dump_device: dev=0xc1bd7580 bus=0xc16b3000 default_pipe=0xc1bd7300 address=2 config=1 depth=1 speed=3 self_powered=0 power=500 langid=1033 usbd_dump_endpoint: endp=0xc1606640 edesc=0xc18267b2 refcnt=1 bEndpointAddress=0x82 (usbd_dump_pipe:) refcnt=1 running=0 aborting=0 intrxfer=0, repeat=0, interval=-1 ehci_device_request: type=0x02, request=0x01, wValue=0x0000, wIndex=0x0082 len=0, addr=2, endpt=0 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4ea0<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008d00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=1 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008d80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc16e0b00 ehci_idone: ex=0xc16e0b00 ehci_idone: xfer=0xc16e0b00, pipe=0xc1bd7300 ready ehci_idone: len=0, actlen=0, cerr=3, status=0x8d00 ehci_ctrl_done: length=0 ehci_idone: ex=0xc16e0b00 done ehci_device_request: type=0xa1, request=0xfe, wValue=0x0000, wIndex=0x0000 len=1, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=1 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=1 curlen=1 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008d00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=1 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x80010d80: toggle=1 bytes=0x1 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=1, actlen=1, cerr=3, status=0x8c00 ehci_ctrl_done: length=1 ehci_idone: ex=0xc1bda500 done umass0:0:0:-1: Attached to scbus0 ehci_device_request: type=0x80, request=0x06, wValue=0x0303, wIndex=0x0409 len=2, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=2 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=2 curlen=2 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4ea0<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x80020d80: toggle=1 bytes=0x2 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=2, actlen=2, cerr=3, status=0x8c00 ehci_ctrl_done: length=2 ehci_idone: ex=0xc1bda500 done ehci_device_request: type=0x80, request=0x06, wValue=0x0303, wIndex=0x0409 len=34, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=34 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=34 curlen=34 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f60<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x80220d80: toggle=1 bytes=0x22 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=34, actlen=34, cerr=3, status=0x8c00 ehci_ctrl_done: length=34 ehci_idone: ex=0xc1bda500 done ehci_device_request: type=0x80, request=0x06, wValue=0x0301, wIndex=0x0409 len=2, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=2 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=2 curlen=2 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x80020d80: toggle=1 bytes=0x2 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=2, actlen=2, cerr=3, status=0x8c00 ehci_ctrl_done: length=2 ehci_idone: ex=0xc1bda500 done ehci_device_request: type=0x80, request=0x06, wValue=0x0301, wIndex=0x0409 len=12, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=12 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=12 curlen=12 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4ea0<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x800c0d80: toggle=1 bytes=0xc ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=12, actlen=12, cerr=3, status=0x8c00 ehci_ctrl_done: length=12 ehci_idone: ex=0xc1bda500 done ehci_device_request: type=0x80, request=0x06, wValue=0x0302, wIndex=0x0409 len=2, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=2 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=2 curlen=2 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f60<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x0d8a4f00<> altnext=0x0d8a4f00<> status=0x80020d80: toggle=1 bytes=0x2 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=2, actlen=2, cerr=3, status=0x8c00 ehci_ctrl_done: length=2 ehci_idone: ex=0xc1bda500 done ehci_device_request: type=0x80, request=0x06, wValue=0x0302, wIndex=0x0409 len=20, addr=2, endpt=0 ehci_alloc_sqtd_chain: start len=20 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=20 curlen=20 ehci_device_request: QH(0xc172dde0) at 0x00261de0: link=0x00261e42 endp=0x80406002 addr=0x02 inact=0 endpt=0 eps=2 dtc=1 hrecl=0 mpl=0x40 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x0d8a4f00<> Overlay qTD: next=0x00000001 altnext=0x00000011 status=0x00008c00: toggle=0 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f00) at 0x0d8a4f00: next=0x0d8a4f60<> altnext=0x0d8a4f60<> status=0x00080e80: toggle=0 bytes=0x8 ioc=0 c_page=0x0 cerr=3 pid=2 stat=0x80 buffer[0]=0x0020aec0 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30f60) at 0x0d8a4f60: next=0x0d8a4ea0<> altnext=0x0d8a4ea0<> status=0x80140d80: toggle=1 bytes=0x14 ioc=0 c_page=0x0 cerr=3 pid=1 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x80008c80: toggle=1 bytes=0x0 ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 ehci_intr1: INT ehci_check_intr: ex=0xc1bda500 ehci_idone: ex=0xc1bda500 ehci_idone: xfer=0xc1bda500, pipe=0xc1bd7300 ready ehci_idone: len=20, actlen=20, cerr=3, status=0x8c00 ehci_ctrl_done: length=20 ehci_idone: ex=0xc1bda500 done ehci_root_ctrl_start: type=0xa3 request=00 ehci_root_ctrl_start: type=0xa3 request=00 ehci_device_bulk_start: xfer=0xc16e0b00 len=31 flags=0 ehci_alloc_sqtd_chain: start len=31 ehci_alloc_sqtd_chain: dataphys=0x0020ae80 dataphyslastpage=0x0020a000 len=31 curlen=31 ehci_device_bulk_start: data(1) QH(0xc172dd80) at 0x00261d80: link=0x00261de2 endp=0x82006102 addr=0x02 inact=0 endpt=1 eps=2 dtc=1 hrecl=0 mpl=0x200 ctl=0 nrl=8 endphub=0x41011c00 smask=0x00 cmask=0x1c huba=0x01 port=2 mult=1 curqtd=0x00000001 Overlay qTD: next=0x00000001 altnext=0x00000001 status=0x00000000: toggle=0 bytes=0x0 ioc=0 c_page=0x0 cerr=0 pid=0 stat=0x0 buffer[0]=0x00000000 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 QTD(0xc1b30ea0) at 0x0d8a4ea0: next=0x00000001 altnext=0x00000001 status=0x001f8c80: toggle=0 bytes=0x1f ioc=1 c_page=0x0 cerr=3 pid=0 stat=0x80 buffer[0]=0x0020ae80 buffer[1]=0x00000000 buffer[2]=0x00000000 buffer[3]=0x00000000 buffer[4]=0x00000000 >How-To-Repeat: Attach a second generation iPod mini to FreeBSD 5.4-STABLE system via USB port. >Fix: >Release-Note: >Audit-Trail: >Unformatted: From owner-freebsd-usb@FreeBSD.ORG Fri Jun 3 13:52:06 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 7157516A41C for ; Fri, 3 Jun 2005 13:52:06 +0000 (GMT) (envelope-from sebastien.b@swissinfo.org) Received: from md1.swissinfo.org (md1.swissinfo.org [146.159.4.92]) by mx1.FreeBSD.org (Postfix) with ESMTP id DA89443D4C for ; Fri, 3 Jun 2005 13:52:05 +0000 (GMT) (envelope-from sebastien.b@swissinfo.org) Received: from mail.swissinfo.org ([194.6.181.33]) by md1.swissinfo.org (phad1.swissinfo.org [146.159.6.9]) (MDaemon.PRO.v7.2.1.R) with ESMTP id 44-md50000500135.msg for ; Fri, 03 Jun 2005 15:33:39 +0200 Received: from [192.168.0.87] (82.216.69.248) by mail.swissinfo.org (7.0.020) (authenticated as sebastien.b) id 4153942003DED505; Fri, 3 Jun 2005 15:33:36 +0200 From: Seb To: hselasky@c2i.net Date: Fri, 3 Jun 2005 15:35:52 +0200 User-Agent: KMail/1.8 References: <200505252120.22408.sebastien.b@swissinfo.org> <200505271331.05132.sebastien.b@swissinfo.org> <200505281531.14351.hselasky@c2i.net> In-Reply-To: <200505281531.14351.hselasky@c2i.net> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline Message-Id: <200506031535.53126.sebastien.b@swissinfo.org> X-Spam-Processed: phad1.swissinfo.org, Fri, 03 Jun 2005 15:33:39 +0200 (not processed: message from valid local sender) X-MDRemoteIP: 194.6.181.33 X-Return-Path: sebastien.b@swissinfo.org X-MDaemon-Deliver-To: freebsd-usb@freebsd.org X-MDAV-Processed: phad1.swissinfo.org, Fri, 03 Jun 2005 15:51:59 +0200 Cc: freebsd-usb@freebsd.org Subject: Re: usbd_bulk_transfer returns 1 (USBD_IN_PROGRESS) ?! X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 03 Jun 2005 13:52:06 -0000 On Saturday 28 May 2005 15:31, Hans Petter Selasky wrote: > On Friday 27 May 2005 13:31, Seb wrote: > > But I didn't fix it with mutexes, I used semaphores instead. > > I initialize a semaphore with a value equal to 1 and then, before the USB > > transfers, I do : > > while(entered) > { > > > mtx_unlock(&Giant); > > sema_wait(&sc->usb_tx_sema); > > mtx_lock(&Giant); > > } > entered = 1; > > > And after the USB transfers : > > sema_post(&sc->usb_tx_sema); > > entered = 0; I'm afraid I don't understand why I should do that. Moreover, if the functions are never called concurrently, the semaphore value will never go down... > > Is this OK ? > > I think it is better you use "sx_xlock", "sx_xunlock" and "sx_init". > See "man sx". What would be the difference with mutexes ? Only so that I can sleep while holding the lock ? Is calling sx_xlock() safe while holding Giant ? The manual page does not specify this... > If you do things via callback you can remove "sc->tx_queues[]" and > associated functions. No, these are also part of Conexant's proprietary protocol. > I think you will get better performance using > callbacks. And most importantly, you are no longer blocking the callers of > those functions that send packets. With the device's protocol which require chained transfers, it will be a mess. That's why I use those software interrupt handlers. Regards, Sebastien From owner-freebsd-usb@FreeBSD.ORG Fri Jun 3 17:45:17 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id F40EB16A41C for ; Fri, 3 Jun 2005 17:45:16 +0000 (GMT) (envelope-from hselasky@c2i.net) Received: from swip.net (mailfe04.swip.net [212.247.154.97]) by mx1.FreeBSD.org (Postfix) with ESMTP id 7C03F43D49 for ; Fri, 3 Jun 2005 17:45:16 +0000 (GMT) (envelope-from hselasky@c2i.net) X-T2-Posting-ID: Y1QAsIk9O44SO+J/q9KNyQ== Received: from mp-216-44-114.daxnet.no ([193.216.44.114] verified) by mailfe04.swip.net (CommuniGate Pro SMTP 4.3.2) with ESMTP id 385723154; Fri, 03 Jun 2005 19:45:14 +0200 From: Hans Petter Selasky To: Seb Date: Fri, 3 Jun 2005 19:45:43 +0200 User-Agent: KMail/1.7 References: <200505252120.22408.sebastien.b@swissinfo.org> <200505281531.14351.hselasky@c2i.net> <200506031535.53126.sebastien.b@swissinfo.org> In-Reply-To: <200506031535.53126.sebastien.b@swissinfo.org> MIME-Version: 1.0 Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: 7bit Content-Disposition: inline Message-Id: <200506031945.44972.hselasky@c2i.net> Cc: freebsd-usb@freebsd.org Subject: Re: usbd_bulk_transfer returns 1 (USBD_IN_PROGRESS) ?! X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list Reply-To: hselasky@c2i.net List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 03 Jun 2005 17:45:17 -0000 On Friday 03 June 2005 15:35, Seb wrote: > On Saturday 28 May 2005 15:31, Hans Petter Selasky wrote: > > On Friday 27 May 2005 13:31, Seb wrote: > > > But I didn't fix it with mutexes, I used semaphores instead. > > > I initialize a semaphore with a value equal to 1 and then, before the > > > USB transfers, I do : > > > > while(entered) > > { > > > > > mtx_unlock(&Giant); > > > sema_wait(&sc->usb_tx_sema); > > > mtx_lock(&Giant); > > > > } > > entered = 1; > > > > > And after the USB transfers : > > > sema_post(&sc->usb_tx_sema); > > > > entered = 0; > Because there might be a race here. Two threads can call "sema_wait()", and when you call "sema_post()" both threads will wake up. Then the first thread will run until the USB code sleeps, and the the second thread will enter into the same USB code causing unpredictable behaviour. > I'm afraid I don't understand why I should do that. > Moreover, if the functions are never called concurrently, the semaphore > value will never go down... > > > > Is this OK ? > > > > I think it is better you use "sx_xlock", "sx_xunlock" and "sx_init". > > See "man sx". > > What would be the difference with mutexes ? Only so that I can sleep while > holding the lock ? see: cat /sys/kern/* | more Type "/_sx_xlock" and press enter. sx-locks allow what is really not a good idea, and that is to sleep while holding a lock. Do you see what can happen if one doesn't exit locks while sleeping: thread_1: lock A; sleep(); unlock A; thread_2: lock A; /* * this code will never be reached if * one doesn't exit lock "A" before * sleeping */ wakeup(); unlock A; > Is calling sx_xlock() safe while holding Giant? Yes. > > > If you do things via callback you can remove "sc->tx_queues[]" and > > associated functions. > > No, these are also part of Conexant's proprietary protocol. Aren't the queues just doing first in first out? You fix some headers and then put the packet onto the queue? But instead of putting the packet onto the second queue you ought to send the packets out right away? --HPS From owner-freebsd-usb@FreeBSD.ORG Sat Jun 4 20:27:20 2005 Return-Path: X-Original-To: freebsd-usb@freebsd.org Delivered-To: freebsd-usb@freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id D028316A41C for ; Sat, 4 Jun 2005 20:27:20 +0000 (GMT) (envelope-from hampi@rootshell.be) Received: from obelix.sunrise.ch (mailrelay3.sunrise.ch [194.158.229.31]) by mx1.FreeBSD.org (Postfix) with ESMTP id D050843D55 for ; Sat, 4 Jun 2005 20:27:19 +0000 (GMT) (envelope-from hampi@rootshell.be) Received: from gicco.homeip.net (pop-ls-8-2-dialup-20.freesurf.ch [194.230.244.20]) by obelix.sunrise.ch (8.12.10/8.12.10) with ESMTP id j54KRHaY004277 for ; Sat, 4 Jun 2005 22:27:17 +0200 Received: from gicco.here (localhost [127.0.0.1]) by gicco.homeip.net (8.13.1/8.13.1) with ESMTP id j54KRCFB002430 for ; Sat, 4 Jun 2005 22:27:12 +0200 (CEST) (envelope-from hampi@rootshell.be) Received: (from idefix@localhost) by gicco.here (8.13.1/8.12.11/Submit) id j54KRBkP002429 for freebsd-usb@freebsd.org; Sat, 4 Jun 2005 22:27:11 +0200 (CEST) (envelope-from hampi@rootshell.be) X-Authentication-Warning: gicco.here: idefix set sender to hampi@rootshell.be using -f Date: Sat, 4 Jun 2005 22:27:11 +0200 From: Hanspeter Roth To: freebsd-usb@freebsd.org Message-ID: <20050604202711.GA2403@gicco.homeip.net> Mail-Followup-To: freebsd-usb@freebsd.org Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.4.2.1i Subject: Atheros based Usb2 Wireless Network Cards X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 04 Jun 2005 20:27:20 -0000 Hello, it seems to me in the ath(4) manpage there are only wireless network cards with PCI or CardBus interface. Are there any that have an USB2 interface that are supported be the ath driver? -Hanspeter From owner-freebsd-usb@FreeBSD.ORG Sat Jun 4 21:12:43 2005 Return-Path: X-Original-To: freebsd-usb@hub.freebsd.org Delivered-To: freebsd-usb@hub.freebsd.org Received: from mx1.FreeBSD.org (mx1.freebsd.org [216.136.204.125]) by hub.freebsd.org (Postfix) with ESMTP id 965B716A41C; Sat, 4 Jun 2005 21:12:43 +0000 (GMT) (envelope-from arved@FreeBSD.org) Received: from freefall.freebsd.org (freefall.freebsd.org [216.136.204.21]) by mx1.FreeBSD.org (Postfix) with ESMTP id 61B3643D1F; Sat, 4 Jun 2005 21:12:43 +0000 (GMT) (envelope-from arved@FreeBSD.org) Received: from freefall.freebsd.org (arved@localhost [127.0.0.1]) by freefall.freebsd.org (8.13.3/8.13.3) with ESMTP id j54LChvY006456; Sat, 4 Jun 2005 21:12:43 GMT (envelope-from arved@freefall.freebsd.org) Received: (from arved@localhost) by freefall.freebsd.org (8.13.3/8.13.1/Submit) id j54LCho4006452; Sat, 4 Jun 2005 21:12:43 GMT (envelope-from arved) Date: Sat, 4 Jun 2005 21:12:43 GMT From: Tilman Linneweh Message-Id: <200506042112.j54LCho4006452@freefall.freebsd.org> To: arved@FreeBSD.org, freebsd-bugs@FreeBSD.org, freebsd-usb@FreeBSD.org Cc: Subject: Re: kern/68232: [patch] ugen(4) isochronous handling correction and tx support X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 04 Jun 2005 21:12:43 -0000 Synopsis: [patch] ugen(4) isochronous handling correction and tx support Responsible-Changed-From-To: freebsd-bugs->freebsd-usb Responsible-Changed-By: arved Responsible-Changed-When: Sat Jun 4 21:12:24 GMT 2005 Responsible-Changed-Why: Over to usb Mailinglist http://www.freebsd.org/cgi/query-pr.cgi?pr=68232