From owner-freebsd-stable@FreeBSD.ORG Wed Oct 17 19:53:55 2007 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id E773016A420; Wed, 17 Oct 2007 19:53:55 +0000 (UTC) (envelope-from lol@chistydom.ru) Received: from comtv.ru (comtv.ru [217.10.32.17]) by mx1.freebsd.org (Postfix) with ESMTP id A49AA13C481; Wed, 17 Oct 2007 19:53:54 +0000 (UTC) (envelope-from lol@chistydom.ru) X-UCL: actv Received: from yoda.org.ru ([83.167.98.162] verified) by comtv.ru (CommuniGate Pro SMTP 4.1.8) with ESMTP id 6506471; Wed, 17 Oct 2007 22:53:52 +0400 Received: from [192.168.102.10] (unknown [192.168.102.10]) (Authenticated sender: llp@soekris.ru) by yoda.org.ru (Postfix) with ESMTP id 6622228BD6; Wed, 17 Oct 2007 22:54:00 +0400 (MSD) Message-ID: <47165A01.1030806@chistydom.ru> Date: Wed, 17 Oct 2007 22:52:49 +0400 From: Alexey Popov User-Agent: Thunderbird 2.0.0.6 (X11/20070924) MIME-Version: 1.0 To: Kris Kennaway References: <47137D36.1020305@chistydom.ru> <47140906.2020107@FreeBSD.org> <47146FB4.6040306@chistydom.ru> <47147E49.9020301@FreeBSD.org> <47149E6E.9000500@chistydom.ru> <4715035D.2090802@FreeBSD.org> <4715C297.1020905@chistydom.ru> <4715C5D7.7060806@FreeBSD.org> In-Reply-To: <4715C5D7.7060806@FreeBSD.org> Content-Type: multipart/mixed; boundary="------------040405020607060803010501" Cc: freebsd-hackers@freebsd.org, freebsd-stable@freebsd.org Subject: Re: amrd disk performance drop after running under high load X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 17 Oct 2007 19:53:56 -0000 This is a multi-part message in MIME format. --------------040405020607060803010501 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Hi Kris Kennaway wrote: >>>> And few hours ago I received feed back from Andrzej Tobola, he has >>>> the same problem on FreeBSD 7 with Promise ATA software mirror: >>> Well, he didnt provide any evidence yet that it is the same problem, >>> so let's not become confused by feelings :) >> I think he is telling about 100% disk busy while processing ~5 >> transfers/sec. > > "% busy" as reported by gstat doesn't mean what you think it does. What > is the I/O response time? That's the meaningful statistic for > evaluating I/O load. Also you didnt post about this. At the problematic time the disk felt to be very slow, processes all were in reading disk state and vmstat proved it by the % numbers. >>>> So I can conclude that FreeBSD has a long standing bug in VM that >>>> could be triggered when serving large amount of static data (much >>>> bigger than memory size) on high rates. Possibly this only applies >>>> to large files like mp3 or video. >>> It is possible, we have further work to do to conclude this though. >> I forgot to mention I have pmc and kgmon profiling for good and bad >> times. But I have not enough knowledge to interpret it right and not >> sure if it can help. > pmc would be useful. Unfortunately i've lost pmc profiling results. I'll try to collect it again later. See vmstats in attach (vmstat -z; netstat -m; vmstat -i; vmstat -w 1 | head -11;). Also you can see kgmon profiling results at: http://83.167.98.162/gprof/ With best regards, Alexey Popov --------------040405020607060803010501 Content-Type: text/plain; name="vmstat-bad.txt" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="vmstat-bad.txt" ITEM SIZE LIMIT USED FREE REQUESTS FAILURES UMA Kegs: 240, 0, 71, 4, 71, 0 UMA Zones: 376, 0, 71, 9, 71, 0 UMA Slabs: 128, 0, 1011, 62, 243081, 0 UMA RCntSlabs: 128, 0, 361, 1205, 363320, 0 UMA Hash: 256, 0, 4, 11, 7, 0 16 Bucket: 152, 0, 45, 30, 72, 0 32 Bucket: 280, 0, 25, 45, 69, 0 64 Bucket: 536, 0, 17, 25, 55, 53 128 Bucket: 1048, 0, 287, 88, 1200, 95423 VM OBJECT: 224, 0, 5536, 23228, 7675004, 0 MAP: 352, 0, 7, 15, 7, 0 KMAP ENTRY: 112, 90222, 283, 1037, 1207524, 0 MAP ENTRY: 112, 0, 1396, 419, 72221561, 0 PV ENTRY: 48, 2244600, 17835, 30261, 768591673, 0 DP fakepg: 120, 0, 0, 31, 10, 0 mt_zone: 1024, 0, 170, 6, 170, 0 16: 16, 0, 3578, 2470, 745206870, 0 32: 32, 0, 1273, 343, 1750850, 0 64: 64, 0, 6147, 1693, 487691440, 0 128: 128, 0, 4659, 387, 1464251, 0 256: 256, 0, 596, 2539, 7208469, 0 512: 512, 0, 608, 253, 791295, 0 1024: 1024, 0, 49, 239, 82867, 0 2048: 2048, 0, 27, 295, 115362, 0 4096: 4096, 0, 240, 278, 564659, 0 Files: 120, 0, 544, 324, 263880246, 0 TURNSTILE: 104, 0, 181, 83, 307, 0 PROC: 856, 0, 82, 82, 308409, 0 THREAD: 608, 0, 169, 11, 24468, 0 KSEGRP: 136, 0, 165, 69, 165, 0 UPCALL: 88, 0, 3, 73, 3, 0 SLEEPQUEUE: 64, 0, 181, 99, 307, 0 VMSPACE: 544, 0, 35, 77, 310929, 0 mbuf_packet: 256, 0, 368, 115, 1331807039, 0 mbuf: 256, 0, 2016, 2331, 5433003167, 0 mbuf_cluster: 2048, 32768, 483, 239, 1236143964, 0 mbuf_jumbo_pagesize: 4096, 0, 0, 0, 0, 0 mbuf_jumbo_9k: 9216, 0, 0, 0, 0, 0 mbuf_jumbo_16k: 16384, 0, 0, 0, 0, 0 ACL UMA zone: 388, 0, 0, 0, 0, 0 g_bio: 216, 0, 4, 410, 48175991, 0 ata_request: 336, 0, 0, 22, 24, 0 ata_composite: 376, 0, 0, 0, 0, 0 VNODE: 496, 0, 28250, 21270, 911708, 0 VNODEPOLL: 152, 0, 0, 0, 0, 0 S VFS Cache: 104, 0, 29153, 9979, 1387950, 0 L VFS Cache: 327, 0, 258, 282, 9423, 0 NAMEI: 1024, 0, 0, 260, 286369405, 0 NFSMOUNT: 584, 0, 1, 6, 1, 0 NFSNODE: 664, 0, 1, 5, 126, 0 DIRHASH: 1024, 0, 278, 122, 1954, 0 PIPE: 768, 0, 35, 335, 253930, 0 KNOTE: 120, 0, 354, 235, 689363256, 0 socket: 616, 49152, 504, 264, 1311349, 0 ipq: 56, 1071, 0, 0, 135, 0 udpcb: 304, 49152, 6, 42, 185368, 0 inpcb: 304, 49152, 384, 192, 903992, 0 tcpcb: 752, 49155, 376, 179, 903992, 0 tcptw: 80, 8235, 8, 487, 211995, 0 syncache: 128, 15370, 0, 145, 890626, 0 hostcache: 136, 15372, 2620, 572, 251887, 0 tcpreass: 40, 2100, 0, 336, 265497, 0 sackhole: 32, 0, 7, 397, 30124600, 0 ripcb: 304, 49152, 0, 36, 64, 0 unpcb: 200, 49153, 40, 340, 221924, 0 rtentry: 264, 0, 6, 36, 26, 0 divcb: 304, 49152, 0, 0, 0, 0 IPFW dynamic rule: 120, 0, 212, 346, 113020, 0 SWAPMETA: 288, 116519, 280, 786, 87016, 0 Mountpoints: 792, 0, 9, 16, 13, 0 FFS inode: 192, 0, 28202, 6158, 911421, 0 FFS1 dinode: 128, 0, 0, 0, 0, 0 FFS2 dinode: 256, 0, 28202, 5713, 911421, 0 2381/2449/4830 mbufs in use (current/cache/total) 368/354/722/32768 mbuf clusters in use (current/cache/total/max) 368/112 mbuf+clusters out of packet secondary zone in use (current/cache) 0/0/0/0 4k (page size) jumbo clusters in use (current/cache/total/max) 0/0/0/0 9k jumbo clusters in use (current/cache/total/max) 0/0/0/0 16k jumbo clusters in use (current/cache/total/max) 1331K/1320K/2651K bytes allocated to network (current/cache/total) 0/0/0 requests for mbufs denied (mbufs/clusters/mbuf+clusters) 0/0/0 requests for jumbo clusters denied (4k/9k/16k) 0/0/0 sfbufs in use (current/peak/max) 0 requests for sfbufs denied 0 requests for sfbufs delayed 8441913 requests for I/O initiated by sendfile 6263 calls to protocol drain routines interrupt total rate irq6: fdc0 8 0 irq14: ata0 47 0 irq16: uhci0 1464547796 1870 irq18: uhci2 12614009 16 irq23: ehci0 3 0 irq46: amr0 12215890 15 irq64: em0 1463513610 1869 cpu0: timer 1564021008 1997 cpu1: timer 1565552539 1999 Total 6082464910 7768 procs memory page disk faults cpu r b w avm fre flt re pi po fr sr am0 in sy cs us sy id 0 2 0 84568 155760 130 3 3 0 298 193 0 771 3421 2251 0 5 95 0 2 0 84576 155488 18 0 0 0 0 0 9 3167 219 7860 0 2 98 0 2 0 84576 155360 0 0 0 0 0 0 2 3568 155 8485 0 1 99 0 2 0 84576 155296 0 0 0 0 0 0 1 2298 110 6218 0 0 100 0 2 0 84576 155232 0 0 0 0 0 0 1 1288 110 4568 0 0 100 0 2 0 84580 154792 1 0 0 0 0 0 10 1459 896 4830 0 1 99 0 2 0 84580 154664 0 0 0 0 0 0 2 2718 128 6911 0 1 99 0 2 0 84580 154376 0 0 0 0 4 0 8 1436 200 4834 0 0 100 0 2 0 84580 154312 0 0 0 0 0 0 1 1500 110 4938 0 0 100 --------------040405020607060803010501 Content-Type: text/plain; name="vmstat-good.txt" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="vmstat-good.txt" ITEM SIZE LIMIT USED FREE REQUESTS FAILURES UMA Kegs: 240, 0, 71, 4, 71, 0 UMA Zones: 376, 0, 71, 9, 71, 0 UMA Slabs: 128, 0, 1003, 70, 237825, 0 UMA RCntSlabs: 128, 0, 502, 2108, 357019, 0 UMA Hash: 256, 0, 4, 11, 7, 0 16 Bucket: 152, 0, 45, 30, 72, 0 32 Bucket: 280, 0, 25, 45, 69, 0 64 Bucket: 536, 0, 17, 25, 55, 53 128 Bucket: 1048, 0, 304, 80, 1200, 95423 VM OBJECT: 224, 0, 4475, 24289, 7583940, 0 MAP: 352, 0, 7, 15, 7, 0 KMAP ENTRY: 112, 90222, 327, 993, 1178293, 0 MAP ENTRY: 112, 0, 1396, 683, 71990087, 0 PV ENTRY: 48, 2244600, 16841, 31255, 764952854, 0 DP fakepg: 120, 0, 0, 31, 10, 0 mt_zone: 1024, 0, 170, 6, 170, 0 16: 16, 0, 3147, 1725, 721283017, 0 32: 32, 0, 1273, 343, 1378831, 0 64: 64, 0, 6161, 1567, 487602322, 0 128: 128, 0, 4658, 388, 1442320, 0 256: 256, 0, 609, 1836, 7119682, 0 512: 512, 0, 608, 253, 781061, 0 1024: 1024, 0, 49, 239, 81907, 0 2048: 2048, 0, 29, 249, 114521, 0 4096: 4096, 0, 239, 294, 558310, 0 Files: 120, 0, 274, 408, 250373577, 0 TURNSTILE: 104, 0, 181, 83, 307, 0 PROC: 856, 0, 82, 82, 304241, 0 THREAD: 608, 0, 169, 11, 24468, 0 KSEGRP: 136, 0, 165, 69, 165, 0 UPCALL: 88, 0, 3, 73, 3, 0 SLEEPQUEUE: 64, 0, 181, 99, 307, 0 VMSPACE: 544, 0, 35, 77, 306723, 0 mbuf_packet: 256, 0, 619, 207, 1297797817, 0 mbuf: 256, 0, 1584, 1190, 5274774672, 0 mbuf_cluster: 2048, 32768, 826, 178, 1203897447, 0 mbuf_jumbo_pagesize: 4096, 0, 0, 0, 0, 0 mbuf_jumbo_9k: 9216, 0, 0, 0, 0, 0 mbuf_jumbo_16k: 16384, 0, 0, 0, 0, 0 ACL UMA zone: 388, 0, 0, 0, 0, 0 g_bio: 216, 0, 0, 270, 47261412, 0 ata_request: 336, 0, 0, 22, 24, 0 ata_composite: 376, 0, 0, 0, 0, 0 VNODE: 496, 0, 26256, 23264, 899305, 0 VNODEPOLL: 152, 0, 0, 0, 0, 0 S VFS Cache: 104, 0, 27155, 11977, 1367768, 0 L VFS Cache: 327, 0, 227, 313, 9350, 0 NAMEI: 1024, 0, 0, 260, 272236181, 0 NFSMOUNT: 584, 0, 1, 6, 1, 0 NFSNODE: 664, 0, 1, 5, 126, 0 DIRHASH: 1024, 0, 278, 122, 1938, 0 PIPE: 768, 0, 35, 335, 250212, 0 KNOTE: 120, 0, 93, 372, 666594974, 0 socket: 616, 49152, 212, 466, 1282315, 0 ipq: 56, 1071, 0, 0, 135, 0 udpcb: 304, 49152, 6, 42, 183757, 0 inpcb: 304, 49152, 225, 351, 877750, 0 tcpcb: 752, 49155, 166, 389, 877750, 0 tcptw: 80, 8235, 59, 436, 204414, 0 syncache: 128, 15370, 0, 145, 864539, 0 hostcache: 136, 15372, 2200, 348, 244865, 0 tcpreass: 40, 2100, 0, 336, 252564, 0 sackhole: 32, 0, 20, 384, 29347536, 0 ripcb: 304, 49152, 0, 36, 64, 0 unpcb: 200, 49153, 40, 340, 220743, 0 rtentry: 264, 0, 6, 36, 26, 0 divcb: 304, 49152, 0, 0, 0, 0 IPFW dynamic rule: 120, 0, 215, 219, 112109, 0 SWAPMETA: 288, 116519, 280, 786, 85846, 0 Mountpoints: 792, 0, 9, 16, 13, 0 FFS inode: 192, 0, 26208, 8152, 899018, 0 FFS1 dinode: 128, 0, 0, 0, 0, 0 FFS2 dinode: 256, 0, 26208, 7722, 899018, 0 2195/1405/3600 mbufs in use (current/cache/total) 619/385/1004/32768 mbuf clusters in use (current/cache/total/max) 619/127 mbuf+clusters out of packet secondary zone in use (current/cache) 0/0/0/0 4k (page size) jumbo clusters in use (current/cache/total/max) 0/0/0/0 9k jumbo clusters in use (current/cache/total/max) 0/0/0/0 16k jumbo clusters in use (current/cache/total/max) 1786K/1121K/2908K bytes allocated to network (current/cache/total) 0/0/0 requests for mbufs denied (mbufs/clusters/mbuf+clusters) 0/0/0 requests for jumbo clusters denied (4k/9k/16k) 0/0/0 sfbufs in use (current/peak/max) 0 requests for sfbufs denied 0 requests for sfbufs delayed 8233198 requests for I/O initiated by sendfile 6116 calls to protocol drain routines interrupt total rate irq6: fdc0 8 0 irq14: ata0 47 0 irq16: uhci0 1428187319 1851 irq18: uhci2 12374352 16 irq23: ehci0 3 0 irq46: amr0 11983237 15 irq64: em0 1427141755 1850 cpu0: timer 1540896452 1997 cpu1: timer 1542377798 1999 Total 5962960971 7730 procs memory page disk faults cpu r b w avm fre flt re pi po fr sr am0 in sy cs us sy id 0 1 0 80564 117716 131 3 3 0 298 191 0 628 3371 1994 0 5 95 0 1 0 80568 117640 5 0 0 0 2 0 10 10265 7724 20485 1 6 93 0 1 0 80568 117400 0 0 0 0 0 0 3 10589 8031 21145 0 8 92 0 1 0 80568 116888 0 0 0 0 0 0 8 11745 8362 22538 0 12 88 0 1 0 80568 116312 0 0 0 0 0 0 9 12191 10091 23571 1 11 88 0 1 0 80568 116184 0 0 0 0 0 0 2 13182 10350 25259 1 12 87 0 2 0 80568 115928 0 0 0 0 0 0 3 12896 8176 24112 0 10 90 0 1 0 80568 115736 0 0 0 0 33 0 4 9527 5090 18717 0 9 91 0 1 0 80568 115608 0 0 0 0 32 0 2 13953 11915 26066 0 11 89 --------------040405020607060803010501--