processes not getting fair share of available disk I/O
Kris Kennaway
kris at obsecurity.org
Thu Dec 14 10:40:17 PST 2006
On Thu, Dec 14, 2006 at 09:07:35AM +0000, Dieter wrote:
> > > > Mutex profiling would show if there is a mutex somehow getting in the
> > > > way of your I/O (e.g. if Giant is somehow being forced). I dont think
> > > > it would show anything though. You can try to study interrupt issues
> > > > (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.
> > >=20
> > > max total count avg cnt_hold cnt_lock name
> > > 1158725 1185330 1596 742 0 0 /usr/src=
> > /sys/amd64/amd64/pmap.c:1563 (pmap)
> > > 1158721 1166593 1596 730 1 17 /usr/src=
> > /sys/amd64/amd64/pmap.c:1562 (vm page queue mutex)
> > > 90598 578551 199304 2 3 4 /usr/src/=
> > sys/kern/kern_sx.c:157 (lockbuilder mtxpool)
> > > 83234 967612 124000 7 0 0 /usr/src/=
> > sys/vm/vm_fault.c:906 (vm object)
>
> > > If I'm reading the man page right, pmap holds a lock for over 1 second?
> >
> > In total, over 1600 operations. It's not an issue.
>
> The man page says:
>
> max The longest continuous hold time in microseconds.
>
> 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.
>
> 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.
>
> 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 /dev/zero
> to a file, sorted by cnt_hold and by cnt_lock.
>
> 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)
>
>
> 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)
>
> And all the stats for dev
>
> 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 at freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-questions
> To unsubscribe, send any mail to "freebsd-questions-unsubscribe at freebsd.org"
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 187 bytes
Desc: not available
Url : http://lists.freebsd.org/pipermail/freebsd-questions/attachments/20061214/71f7c7b2/attachment-0001.pgp
More information about the freebsd-questions
mailing list