From owner-freebsd-usb@freebsd.org Mon Feb 24 01:20:34 2020 Return-Path: Delivered-To: freebsd-usb@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id A544E24E95B for ; Mon, 24 Feb 2020 01:20:34 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from mailman.nyi.freebsd.org (mailman.nyi.freebsd.org [IPv6:2610:1c1:1:606c::50:13]) by mx1.freebsd.org (Postfix) with ESMTP id 48QklQ3t7Yz4GTX for ; Mon, 24 Feb 2020 01:20:34 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: by mailman.nyi.freebsd.org (Postfix) id 832A324E95A; Mon, 24 Feb 2020 01:20:34 +0000 (UTC) Delivered-To: usb@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id 82E1824E958 for ; Mon, 24 Feb 2020 01:20:34 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from mxrelay.nyi.freebsd.org (mxrelay.nyi.freebsd.org [IPv6:2610:1c1:1:606c::19:3]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) server-signature RSA-PSS (4096 bits) client-signature RSA-PSS (4096 bits) client-digest SHA256) (Client CN "mxrelay.nyi.freebsd.org", Issuer "Let's Encrypt Authority X3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 48QklQ2y0Tz4GTV for ; Mon, 24 Feb 2020 01:20:34 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from kenobi.freebsd.org (kenobi.freebsd.org [IPv6:2610:1c1:1:606c::50:1d]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) server-signature RSA-PSS (4096 bits)) (Client did not present a certificate) by mxrelay.nyi.freebsd.org (Postfix) with ESMTPS id 5AD801D7B0 for ; Mon, 24 Feb 2020 01:20:34 +0000 (UTC) (envelope-from bugzilla-noreply@freebsd.org) Received: from kenobi.freebsd.org ([127.0.1.5]) by kenobi.freebsd.org (8.15.2/8.15.2) with ESMTP id 01O1KYES027528 for ; Mon, 24 Feb 2020 01:20:34 GMT (envelope-from bugzilla-noreply@freebsd.org) Received: (from www@localhost) by kenobi.freebsd.org (8.15.2/8.15.2/Submit) id 01O1KYNL027527 for usb@FreeBSD.org; Mon, 24 Feb 2020 01:20:34 GMT (envelope-from bugzilla-noreply@freebsd.org) X-Authentication-Warning: kenobi.freebsd.org: www set sender to bugzilla-noreply@freebsd.org using -f From: bugzilla-noreply@freebsd.org To: usb@FreeBSD.org Subject: [Bug 244356] Writing to a USB 3.0 stick is very slow Date: Mon, 24 Feb 2020 01:20:31 +0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: new X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: Base System X-Bugzilla-Component: usb X-Bugzilla-Version: 12.1-RELEASE X-Bugzilla-Keywords: X-Bugzilla-Severity: Affects Only Me X-Bugzilla-Who: seb@boisvert.info X-Bugzilla-Status: New X-Bugzilla-Resolution: X-Bugzilla-Priority: --- X-Bugzilla-Assigned-To: usb@FreeBSD.org X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: bug_id short_desc product version rep_platform op_sys bug_status bug_severity priority component assigned_to reporter Message-ID: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Bugzilla-URL: https://bugs.freebsd.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 24 Feb 2020 01:20:34 -0000 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D244356 Bug ID: 244356 Summary: Writing to a USB 3.0 stick is very slow Product: Base System Version: 12.1-RELEASE Hardware: amd64 OS: Any Status: New Severity: Affects Only Me Priority: --- Component: usb Assignee: usb@FreeBSD.org Reporter: seb@boisvert.info Hello, Writing to a USB 3.0 stick is very slow. USB 2.0 sticks work fine. USB 3.0 stick plugged in a USB 2.0 port exhibit the same problem compared to being plugged in a USB 3.0 port. My FreeBSD installation is on a ZFS mirror of 2 identical 7.2 GiB USB 2.0 sticks. Output of 'usbconfig' for these 2 storage devices: ugen1.2: at usbus1, cfg=3D0 md=3DHOST spd=3DHIGH (480Mbps) pwr=3DON (100mA) ugen0.3: at usbus0, cfg=3D0 md=3DHOST spd=3DHIGH (480Mbps) pwr=3DON (100mA) Output of gpart: root@atlantis:~ # gpart show da0 =3D> 40 15131560 da0 GPT (7.2G) 40 1024 1 freebsd-boot (512K) 1064 984 - free - (492K) 2048 4194304 2 freebsd-swap (2.0G) 4196352 10934272 3 freebsd-zfs (5.2G) 15130624 976 - free - (488K) root@atlantis:~ # gpart show da1 =3D> 40 15131560 da1 GPT (7.2G) 40 1024 1 freebsd-boot (512K) 1064 984 - free - (492K) 2048 4194304 2 freebsd-swap (2.0G) 4196352 10934272 3 freebsd-zfs (5.2G) 15130624 976 - free - (488K) The directory /usr contains 620 MB of files. Command: # du -sh /usr/ 620M /usr/ It takes 4:31.4 (4 minutes, 31 seconds) to copy /usr to /root. Command: time rsync -av /usr /root/ sent 1,458,070,436 bytes received 952,593 bytes 5,354,212.95 bytes/sec total size is 1,454,334,520 speedup is 1.00 13.724u 17.240s 4:31.94 11.3% 433+221k 59891+57303io 0pf+0w I have a 32 GB USB 3.0 stick. The output of 'usbconfig' is: ugen0.5: at usbus0, cfg=3D0 md=3DHOST spd=3DSUP= ER (5.0Gbps) pwr=3DON (126mA) The output of 'gpart': root@atlantis:~ # gpart show da2 =3D> 40 60604336 da2 GPT (29G) 40 2008 - free - (1.0M) 2048 60600320 1 freebsd-ufs (29G) 60602368 2008 - free - (1.0M) There is a UFS file system on the USB 3.0 devive. It is mounted in /mnt/ufs It takes 31:34.57 to copy /usr to /mnt/ufs, Command: time rsync -av /usr/ /mnt/ufs/ sent 1,458,070,404 bytes received 952,532 bytes 770,136.15 bytes/sec total size is 1,454,334,520 speedup is 1.00 13.128u 12.211s 31:34.57 1.3% 435+222k 7678+9104io 0pf+0w Using 'truss', I can see that a lot of calls to select() take a lot of time before returning. Command:=20 truss -D rsync -av /usr /mnt/ufs/ >& /root/rsync-truss-ufs-usb-3.log root@atlantis:~ # sort -k1,1rn /root/rsync-truss-ufs-usb-3.log | head -n 20 60.003431924 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 0 (0x0) 49.165728175 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 42.159206222 select(5,{ },{ 4 },{ },{ 60.000000 }) =3D 1 (0x1) 41.122681159 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 39.143298378 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 38.106784375 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 38.080823335 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 33.890768013 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 32.247561086 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 29.721087531 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 28.045373886 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 27.097321654 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 26.624814418 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 26.183747112 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 23.386795589 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 22.540706824 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 22.448082140 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 21.807824638 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 21.662166794 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) 17.910288782 select(6,{ 5 },{ 4 },{ 5 },{ 60.000000 }) =3D 1 (0x1) Using the 'procsystime' dtrace script, I can see the numerous calls to select(). root@atlantis:~ # /usr/local/share/dtrace-toolkit/procsystime Tracing... Hit Ctrl-C to end... dtrace: 357 dynamic variable drops with non-empty dirty list ^C Elapsed Times for all processes, SYSCALL TIME (ns) sigreturn 4899 open 5961 fstatfs 6843 close 8286 openat 13816 fstat 17242 sigaction 22701 mmap 30375 fstatat 39743 getdirentries 40936 sigprocmask 99694 write 633885 __sysctl 873677 ioctl 1227846 read 1428213 _umtx_op 9038575168 select 17245685291 The 'hotkernel' dtrace script shows that the CPU cores are mostly idle. root@atlantis:~ # /usr/local/share/dtrace-toolkit/hotkernel=20 Sampling... Hit Ctrl-C to end. ^C FUNCTION COUNT PCNT kernel`cpu_activeclock 1 0.0% kernel`acpi_cpu_idle 1 0.0% kernel`usbd_in_polling_mode 1 0.0% kernel`xhci_generic_done_sub 1 0.0% kernel`critical_exit_preempt 1 0.0% kernel`softdep_sync_buf 1 0.0% kernel`rdtsc 1 0.0% kernel`cpu_idle_acpi 2 0.0% kernel`ithread_loop 2 0.0% kernel`usbd_get_page 2 0.0% kernel`xhci_setup_generic_chain_sub 3 0.0% kernel`em_update_stats_counters 3 0.0% kernel`tsc_get_timecount_low_mfence 4 0.0% kernel`cpu_search_highest 7 0.0% kernel`xhci_interrupt_poll 8 0.0% kernel`xhci_interrupt 16 0.0% kernel`spinlock_exit 36 0.0% kernel`cpu_idle 2888 3.4% kernel`acpi_cpu_c1 81118 96.5% The 'disklatency' dtrace script shows a high disk latency. root@atlantis:~ # /usr/share/dtrace/disklatency Tracing... Hit Ctrl-C to end. ^C da 2 value ------------- Distribution ------------- count=20=20=20=20 76000 | 0=20=20=20=20=20= =20=20=20 >=3D 80000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2=20=20=20=20= =20=20=20=20 da 2 2131= 761 da 2 2121= 442 da 2 10= 420 ZFS is completely unusable on this USB 3.0 stick. It took the whole night just to install FreeBSD on ZFS using the installer. Hardware -------- - Processor: AMD Ryzen 5 2600 Six-Core Processor - Socket: AM4 - Memory: Kingston 8GB DDR4-2400ECC Unbuffered DIMM CL171Rx81.2V Micron EDie (Server Premier) - Motherboard: ASRock B450 Gaming-ITX/ac - Chipset: AMD Promontory B450 - Storage (operating system): 2 x Kingston DataTraveler 2.0 7.2 GiB - Storage: Kingston DataTraveler 3.0 PHISON USB3 --=20 You are receiving this mail because: You are the assignee for the bug.=