Date: Thu, 14 Dec 2006 13:25:17 -0500 From: Kris Kennaway <kris@obsecurity.org> To: Dieter <freebsd@sopwith.solgatos.com> Cc: freebsd-questions@freebsd.org Subject: Re: processes not getting fair share of available disk I/O Message-ID: <20061214182517.GA94080@xor.obsecurity.org> In-Reply-To: <200612141707.RAA26563@sopwith.solgatos.com> References: <20061214074133.GA67465@xor.obsecurity.org> <200612141707.RAA26563@sopwith.solgatos.com>
next in thread | previous in thread | raw e-mail | index | archive | help
--zYM0uCDKw75PZbzx Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable On Thu, Dec 14, 2006 at 09:07:35AM +0000, Dieter wrote: > > > > Mutex profiling would show if there is a mutex somehow getting in t= he > > > > way of your I/O (e.g. if Giant is somehow being forced). I dont th= ink > > > > it would show anything though. You can try to study interrupt issu= es > > > > (e.g. look for an interrupt storm during I/O) with vmstat -i. Other > > > > than that you'd probably have to get your hands dirtier in the code. > > >=3D20 > > > max total count avg cnt_hold cnt_lock name > > > 1158725 1185330 1596 742 0 0 /usr= /src=3D > > /sys/amd64/amd64/pmap.c:1563 (pmap) > > > 1158721 1166593 1596 730 1 17 /usr= /src=3D > > /sys/amd64/amd64/pmap.c:1562 (vm page queue mutex) > > > 90598 578551 199304 2 3 4 /usr/= src/=3D > > sys/kern/kern_sx.c:157 (lockbuilder mtxpool) > > > 83234 967612 124000 7 0 0 /usr/= src/=3D > > sys/vm/vm_fault.c:906 (vm object) >=20 > > > If I'm reading the man page right, pmap holds a lock for over 1 secon= d? > >=20 > > In total, over 1600 operations. It's not an issue. >=20 > The man page says: >=20 > max The longest continuous hold time in microseconds. >=20 > Which together with the total number, would imply 1 time it took 1.158725= seconds, > and the other 1595 times averaged 16.7 usec, which seems unlikely. >=20 > Am I misinterpreting the man page? Sorry, yes. Nothing else contended for it though, so it doesn't appear to be a source of performance problems - it is probably a secondary effect from something else. I guess you're running some old version of FreeBSD since those line numbers don't correspond to anything reasonable in the current 6.x source, so I dunno what exactly. > > The rest looks fine at a quick glance too. >=20 > What should I be looking for? Do I need to collect stats for a long > period of time, or is a few seconds enough? Dd can kill the transfer > in about 3 seconds. You need to make sure your sampling while the system is in the bad state. A mutex that has a lot of acquisitions and a lot of contention for those acquisitions is a performance bottleneck. Nothing below falls into that class - in particular it's definitely not Giant causing performance loss to the filesystem. Still looks like it's a driver and/or hardware problem, but you'd need specialized knowledge to proceed with debugging it. > Here are stats with the Ethernet->disk program competing with dd from /de= v/zero > to a file, sorted by cnt_hold and by cnt_lock. >=20 > max total count avg cnt_hold cnt_lock name > 89 6095988 1089530 5 536 979 /usr/src/= sys/kern/kern_intr.c:546 (Giant) > 2649 1950594 360310 5 449 0 /usr/src/= sys/netinet/tcp_usrreq.c:598 (tcp) > 13553 2348809 23610 99 350 2 /usr/src/= sys/kern/kern_sysctl.c:1280 (Giant) > 36 230008 85274 2 141 241 /usr/src/= sys/kern/kern_timeout.c:258 (Giant) > 453 300251 180186 1 89 0 /usr/src/= sys/kern/uipc_socket.c:1011 (so_rcv) > 199878 2351641 4706 499 88 4 /usr/src/= sys/kern/kern_synch.c:236 (Giant) > 2138 337086 180186 1 85 0 /usr/src/= sys/kern/uipc_socket.c:1255 (so_rcv) > 67 1120044 722561 1 83 0 /usr/src/= sys/kern/subr_taskqueue.c:219 (taskqueue) > 57 219660 134214 1 70 102 /usr/src/= sys/netinet/tcp_subr.c:1404 (tcp) > 73 1830084 180344 10 65 0 /usr/src/= sys/dev/bge/if_bge.c:3321 (bge0) > 472 272697 180155 1 63 0 /usr/src/= sys/kern/uipc_socket.c:1401 (so_rcv) > 77 541532 361447 1 48 0 /usr/src/= sys/kern/subr_taskqueue.c:204 (taskqueue) > 5198 26977 244 110 26 1 /usr/src/= sys/kern/kern_exit.c:233 (Giant) > 50 545822 361062 1 26 0 /usr/src/= sys/net/netisr.c:233 (ip_inq) > 1649 287241 102509 2 24 30 /usr/src/= sys/kern/vfs_bio.c:1397 (buf queue lock) > 20981 212022 9317 22 19 2 /usr/src/= sys/vm/vm_fault.c:683 (vm object) > 65 26162 3656 7 18 4 /usr/src/= sys/kern/kern_conf.c:324 (Giant) > 7546 218853 412 531 17 1 /usr/src/= sys/amd64/amd64/pmap.c:2481 (vm page queue mutex) > 110 13982 244 57 17 0 /usr/src/= sys/kern/kern_exit.c:385 (Giant) > 491 278319 170512 1 16 2 /usr/src/= sys/kern/kern_synch.c:238 (process lock) > 52 27355 2279 12 16 9 /usr/src/= sys/net/netisr.c:339 (Giant) > 576 27530 1379 19 15 5307 /usr/src/= sys/kern/kern_conf.c:312 (Giant) > 75 75460 1344 56 15 0 /usr/src/= sys/dev/bge/if_bge.c:3088 (bge0) > 3903 49655 11221 4 11 9 /usr/src/= sys/vm/vnode_pager.c:1169 (vm object) > 658 88609 48732 1 11 4 /usr/src/= sys/kern/vfs_bio.c:309 (needsbuffer lock) > 182 198222 127109 1 11 4 /usr/src/= sys/vm/vm_fault.c:907 (vm page queue mutex) > 5883 382321 103647 3 10 0 /usr/src/= sys/kern/vfs_bio.c:2350 (vnode interlock) > 273 34597 19322 1 9 4 /usr/src/= sys/kern/vfs_bio.c:1297 (buf queue lock) > 82 275004 180344 1 9 1 /usr/src/= sys/net/if_ethersubr.c:408 (bge0) > 576 206209 67474 3 8 22 /usr/src/= sys/kern/vfs_bio.c:3365 (vm page queue mutex) >=20 >=20 > max total count avg cnt_hold cnt_lock name > 576 27530 1379 19 15 5307 /usr/src/= sys/kern/kern_conf.c:312 (Giant) > 89 6095988 1089530 5 536 979 /usr/src/= sys/kern/kern_intr.c:546 (Giant) > 478 192375 123859 1 8 827 /usr/src/= sys/vm/vm_fault.c:849 (vm page queue mutex) > 155 759634 362384 2 0 427 /usr/src/= sys/dev/bge/if_bge.c:2916 (bge0) > 58 955483 180013 5 0 257 /usr/src/= sys/netinet/tcp_input.c:1280 (so_rcv) > 145 8595737 180735 47 0 250 /usr/src/= sys/netinet/tcp_input.c:742 (inp) > 36 230008 85274 2 141 241 /usr/src/= sys/kern/kern_timeout.c:258 (Giant) > 615 60464 5683 10 0 187 /usr/src/= sys/kern/vfs_bio.c:1456 (vm object) > 149 618529 180736 3 0 183 /usr/src/= sys/netinet/tcp_input.c:615 (tcp) > 29 1155402 723611 1 0 139 /usr/src/= sys/kern/subr_taskqueue.c:158 (taskqueue) > 57 219660 134214 1 70 102 /usr/src/= sys/netinet/tcp_subr.c:1404 (tcp) > 54 5116 667 7 0 94 /usr/src/= sys/netinet/tcp_usrreq.c:629 (tcp) > 499 149258 17011 8 1 49 /usr/src/= sys/kern/vfs_bio.c:1665 (buf queue lock) > 47 259969 169782 1 0 33 /usr/src/= sys/kern/sys_generic.c:1140 (sellck) > 36 456802 302786 1 0 31 /usr/src/= sys/kern/vfs_subr.c:2814 (vnode interlock) > 1649 287241 102509 2 24 30 /usr/src/= sys/kern/vfs_bio.c:1397 (buf queue lock) > 205 24243 14011 1 6 26 /usr/src/= sys/vm/vm_fault.c:344 (vm page queue mutex) > 24 276097 180742 1 0 26 /usr/src/= sys/net/if.c:2236 (ip_inq) > 2811 29673 10778 2 0 25 /usr/src/= sys/vm/vm_map.c:2193 (vm object) > 576 206209 67474 3 8 22 /usr/src/= sys/kern/vfs_bio.c:3365 (vm page queue mutex) > 7564 120517 16144 7 4 21 /usr/src/= sys/kern/vfs_bio.c:3082 (vm object) > 295 40504 22674 1 3 18 /usr/src/= sys/kern/vfs_bio.c:1413 (vnode interlock) > 276 33918 16144 2 1 14 /usr/src/= sys/kern/vfs_bio.c:3101 (vm page queue mutex) > 2054 31157 15635 1 4 12 /usr/src/= sys/kern/vfs_subr.c:1983 (vnode interlock) > 48 1846 883 2 0 12 /usr/src/= sys/ufs/ffs/ffs_softdep.c:4724 (Softdep Lock) > 661 33248 9645 3 2 11 /usr/src/= sys/kern/vfs_cache.c:356 (Name Cache) > 563 7078 3920 1 3 11 /usr/src/= sys/vm/vm_object.c:1194 (vm object) > 274 42309 24962 1 3 10 /usr/src/= sys/kern/vfs_bio.c:351 (needsbuffer lock) > 27 544145 360697 1 0 10 /usr/src/= sys/dev/bge/if_bge.c:3245 (bge0) > 3903 49655 11221 4 11 9 /usr/src/= sys/vm/vnode_pager.c:1169 (vm object) >=20 > And all the stats for dev >=20 > max total count avg cnt_hold cnt_lock name > 528 249014 156914 1 0 0 /usr/src/sys= /dev/acpica/Osd/OsdSynch.c:301 (ACPI semaphore) > 503 151513 10773 14 0 0 /usr/src/sys= /dev/ata/ata-queue.c:168 (ATA queue lock) > 499 108638 8732 12 0 0 /usr/src/sys= /dev/ata/ata-queue.c:185 (ATA state lock) > 418 11820 5386 2 0 4 /usr/src/sys= /dev/ata/ata-queue.c:80 (ATA queue lock) > 320 115812 2637 43 0 0 /usr/src/sys= /dev/random/yarrow.c:193 (random reseed) > 309 98547 55775 1 3 6 /usr/src/sys= /kern/kern_conf.c:62 (cdev) > 194 897 5 179 1 0 /usr/src/sys= /fs/devfs/devfs_vnops.c:285 (Giant) > 155 759634 362384 2 0 427 /usr/src/sys= /dev/bge/if_bge.c:2916 (bge0) > 138 240285 156914 1 0 0 /usr/src/sys= /dev/acpica/Osd/OsdSynch.c:183 (ACPI semaphore) > 75 75460 1344 56 15 0 /usr/src/sys= /dev/bge/if_bge.c:3088 (bge0) > 73 1830084 180344 10 65 0 /usr/src/sys= /dev/bge/if_bge.c:3321 (bge0) > 62 157 19 8 0 0 /usr/src/sys= /fs/devfs/devfs_vnops.c:269 (vnode interlock) > 48 151 4 37 0 0 /usr/src/sys= /dev/random/yarrow.c:280 (random reseed) > 46 22508 5387 4 0 0 /usr/src/sys= /dev/ata/ata-all.c:327 (ATA state lock) > 32 3642 2421 1 0 0 /usr/src/sys= /kern/subr_devstat.c:394 (devstat) > 29 282384 180059 1 0 0 /usr/src/sys= /dev/bge/if_bge.c:2840 (bge0) > 27 544145 360697 1 0 10 /usr/src/sys= /dev/bge/if_bge.c:3245 (bge0) > 9 27 3 9 0 0 /usr/src/sys= /fs/devfs/devfs_vnops.c:245 (session) > 5 15 3 5 0 0 /usr/src/sys= /fs/devfs/devfs_vnops.c:246 (vnode interlock) > 5 5 1 5 0 0 /usr/src/sys= /fs/devfs/devfs_vnops.c:157 (vnode interlock) > 3 8 3 2 0 0 /usr/src/sys= /vm/swap_pager.c:652 (swapdev) > 1 406 269 1 0 0 /usr/src/sys= /kern/subr_devstat.c:381 (devstat) > 1 214 134 1 0 0 /usr/src/sys= /dev/acpica/acpi_thermal.c:753 (ACPI thermal zone) > 1 207 134 1 0 0 /usr/src/sys= /dev/acpica/acpi_thermal.c:745 (ACPI thermal zone) > 1 23 15 1 0 0 /usr/src/sys= /fs/devfs/devfs_vnops.c:530 (dev_clone) > 1 4 3 1 0 0 /usr/src/sys= /kern/kern_conf.c:77 (cdev) > 1 1 1 1 0 0 /usr/src/sys= /vm/swap_pager.c:621 (swapdev) > _______________________________________________ > freebsd-questions@freebsd.org mailing list > http://lists.freebsd.org/mailman/listinfo/freebsd-questions > To unsubscribe, send any mail to "freebsd-questions-unsubscribe@freebsd.o= rg" >=20 --zYM0uCDKw75PZbzx Content-Type: application/pgp-signature Content-Disposition: inline -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (FreeBSD) iD8DBQFFgZcNWry0BWjoQKURAiSSAJ9ZpM1s2+OIHWUP5EZCruNfpLj1oACeOmPx Zct3+/F6likEbHs4MkRfbpM= =izIX -----END PGP SIGNATURE----- --zYM0uCDKw75PZbzx--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20061214182517.GA94080>