Subject: Re: possible kernel bug: stat mclpl after heavy net load
To: Pavel Cahyna <pavel.cahyna@st.mff.cuni.cz>
From: Stephan Pietzko <netbsd@wiki.uni-konstanz.de>
List: current-users
Date: 12/17/2005 08:01:41
Pavel Cahyna <pcah8322@artax.karlin.mff.cuni.cz> wrote
> > >
> > > I see a very similiar thing, but with nfsd rather than httpd, and on an
> > > x86 system running current from this past weekend. And it's after
> > > very heavy nfs load.
> > Than it would be a general kernel-bug in the network memory pool?!
> > How can i debug the problem or get more information about it?
> >
> > For now i wait for the next crash.
In the meantime i had the next crash. After around 800G uploadtraffic.
GENERIC-kernel, netbsd-2 build form the source (6. dec), thttpd with
high load. In crashed state (thttpd hangs not killable with -9, rest
works) i made ps -aux, lsof -i, vmstat -m, netstat -m, in addition i
have greped netstat -m and mbpl and mclpl out of vmstat -m every 10
minutes.
What info is interesting vor debugging?
> compile a kernel with 'options SOSEND_NO_LOAN' ?
Ok - i try this
tnx Stephan
----------------------------------------------------------------------
here some outputs
line of thttpd from ps -aux
www 307 0.0 0.0 2416 163208 ?? DWNs Wed08PM 508:30.23 /usr/pkg/sbin/thttpd -C /usr/pkg/etc/thttpd.conf
10min log from vmstat -m | grep mbpl around the crash (the number bevor the hour is the day)
16.16:00:00 mbpl 256 5019435 0 5016533 2445 2326 119 163 1 inf 0
16.16:10:00 mbpl 256 5045161 0 5041878 2445 2331 114 163 1 inf 0
16.16:20:01 mbpl 256 5067090 0 5063567 2452 2332 120 163 1 inf 0
16.16:30:00 mbpl 256 5089980 0 5086830 2454 2335 119 163 1 inf 0
16.16:40:00 mbpl 256 5105932 0 5102777 2455 2338 117 163 1 inf 0
16.16:50:01 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.17:00:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.17:10:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.17:20:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.17:30:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.17:40:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.17:50:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.18:00:01 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.18:10:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.18:20:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.18:30:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.18:40:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.18:50:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.19:00:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.19:10:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.19:20:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.19:30:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.19:40:01 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.19:50:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.20:00:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.20:10:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.20:20:00 mbpl 256 5115475 0 5110123 2513 2339 174 174 1 inf 1
16.20:30:00 mbpl 256 606 0 0 21 0 21 21 1 inf 1
16.20:40:00 mbpl 256 1017 0 251 27 1 26 26 1 inf 1
16.20:50:01 mbpl 256 2853 0 1187 61 3 58 58 1 inf 0
16.21:00:00 mbpl 256 4563 0 2730 69 5 64 65 1 inf 0
16.21:10:00 mbpl 256 6568 0 4604 77 6 71 71 1 inf 0
16.21:20:00 mbpl 256 9267 0 6726 90 7 83 83 1 inf 1
16.21:30:00 mbpl 256 11069 0 9091 90 8 82 83 1 inf 0
16.21:40:00 mbpl 256 13081 0 11107 90 9 81 83 1 inf 0
16.21:50:00 mbpl 256 15754 0 14123 90 12 78 83 1 inf 1
16.22:00:00 mbpl 256 20872 0 18389 94 13 81 83 1 inf 0
16.22:10:00 mbpl 256 26631 0 24500 101 15 86 87 1 inf 0
16.22:20:01 mbpl 256 31364 0 29014 101 15 86 87 1 inf 1
16.22:30:00 mbpl 256 39026 0 36182 118 17 101 101 1 inf 0
16.22:40:00 mbpl 256 45350 0 42404 118 18 100 101 1 inf 0
16.22:50:00 mbpl 256 51812 0 48785 120 19 101 101 1 inf 0
16.23:00:01 mbpl 256 58597 0 55446 123 20 103 103 1 inf 0
16.23:10:00 mbpl 256 67293 0 65211 135 22 113 114 1 inf 0
16.23:20:00 mbpl 256 77051 0 73815 135 23 112 114 1 inf 0
16.23:30:00 mbpl 256 83872 0 80665 135 25 110 114 1 inf 0
16.23:40:00 mbpl 256 89073 0 85984 135 25 110 114 1 inf 0
16.23:50:00 mbpl 256 97270 0 94117 135 27 108 114 1 inf 0
17.00:00:01 mbpl 256 103246 0 100352 138 28 110 114 1 inf 0
17.00:10:01 mbpl 256 108555 0 105895 138 30 108 114 1 inf 0
17.00:20:01 mbpl 256 113704 0 110971 138 32 106 114 1 inf 0
17.00:30:00 mbpl 256 119028 0 116019 138 34 104 114 1 inf 0
17.00:40:00 mbpl 256 123046 0 120908 139 35 104 114 1 inf 0
17.00:50:00 mbpl 256 125585 0 123430 139 36 103 114 1 inf 0
same with mclpl
16.16:00:00 mclpl 2048 936092 0 935569 32001 31862 139 218 2 256 4
16.16:10:00 mclpl 2048 941561 0 940912 32098 31932 166 218 2 256 0
16.16:20:01 mclpl 2048 947167 0 946444 32177 31991 186 218 2 256 0
16.16:30:00 mclpl 2048 951872 0 951229 32235 32060 175 218 2 256 2
16.16:40:00 mclpl 2048 955126 0 954505 32272 32109 163 218 2 256 1
16.16:50:01 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.17:00:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.17:10:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.17:20:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.17:30:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.17:40:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.17:50:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.18:00:01 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.18:10:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.18:20:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.18:30:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.18:40:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.18:50:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.19:00:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.19:10:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.19:20:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.19:30:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.19:40:01 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.19:50:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.20:00:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.20:10:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.20:20:00 mclpl 2048 957082 0 956070 32378 32125 253 253 2 256 0
16.20:30:00 mclpl 2048 118 0 0 32 0 32 32 2 256 2
16.20:40:00 mclpl 2048 210 0 59 45 5 40 40 2 256 2
16.20:50:01 mclpl 2048 592 0 265 98 13 85 87 2 256 0
16.21:00:00 mclpl 2048 891 0 480 126 21 105 105 2 256 2
16.21:10:00 mclpl 2048 1212 0 802 149 34 115 117 2 256 0
16.21:20:00 mclpl 2048 1741 0 1216 178 44 134 134 2 256 2
16.21:30:00 mclpl 2048 2162 0 1732 178 52 126 134 2 256 1
16.21:40:00 mclpl 2048 2587 0 2139 181 66 115 134 2 256 0
16.21:50:00 mclpl 2048 3213 0 2907 205 78 127 134 2 256 8
16.22:00:00 mclpl 2048 4315 0 3768 228 89 139 139 2 256 2
16.22:10:00 mclpl 2048 5291 0 4787 240 103 137 141 2 256 0
16.22:20:01 mclpl 2048 6200 0 5704 250 119 131 141 2 256 0
16.22:30:00 mclpl 2048 7522 0 6960 289 137 152 154 2 256 0
16.22:40:00 mclpl 2048 8776 0 8186 301 151 150 154 2 256 2
16.22:50:00 mclpl 2048 9929 0 9469 322 166 156 159 2 256 3
16.23:00:01 mclpl 2048 11142 0 10516 337 178 159 160 2 256 1
16.23:10:00 mclpl 2048 12814 0 12416 368 201 167 169 2 256 31
16.23:20:00 mclpl 2048 14636 0 14005 375 211 164 174 2 256 1
16.23:30:00 mclpl 2048 15794 0 15176 382 222 160 174 2 256 0
16.23:40:00 mclpl 2048 16729 0 16119 385 230 155 174 2 256 2
16.23:50:00 mclpl 2048 18099 0 17475 404 246 158 174 2 256 2
17.00:00:01 mclpl 2048 19189 0 18593 421 260 161 174 2 256 2
17.00:10:01 mclpl 2048 20329 0 19783 424 279 145 174 2 256 0
17.00:20:01 mclpl 2048 21364 0 20806 438 289 149 174 2 256 0
17.00:30:00 mclpl 2048 22431 0 21823 460 306 154 174 2 256 1
17.00:40:00 mclpl 2048 23255 0 22762 475 327 148 174 2 256 1
17.00:50:00 mclpl 2048 23728 0 23254 475 344 131 174 2 256 0
same with netstat -m only data
16.16:00:00 793 mbufs in use: 717 mbufs allocated to data
16.16:10:00 1070 mbufs in use: 1000 mbufs allocated to data
16.16:20:01 1620 mbufs in use: 1549 mbufs allocated to data
16.16:30:00 1247 mbufs in use: 1179 mbufs allocated to data
16.16:40:00 1578 mbufs in use: 1514 mbufs allocated to data
16.16:50:01 820 mbufs in use: 633 mbufs allocated to data
16.17:00:00 977 mbufs in use: 741 mbufs allocated to data
16.17:10:00 976 mbufs in use: 741 mbufs allocated to data
16.17:20:00 975 mbufs in use: 741 mbufs allocated to data
16.17:30:00 974 mbufs in use: 741 mbufs allocated to data
16.17:40:00 974 mbufs in use: 741 mbufs allocated to data
16.17:50:00 973 mbufs in use: 741 mbufs allocated to data
16.18:00:01 899 mbufs in use: 668 mbufs allocated to data
16.18:10:00 899 mbufs in use: 668 mbufs allocated to data
16.18:20:00 899 mbufs in use: 668 mbufs allocated to data
16.18:30:00 899 mbufs in use: 668 mbufs allocated to data
16.18:40:00 899 mbufs in use: 668 mbufs allocated to data
16.18:50:00 899 mbufs in use: 668 mbufs allocated to data
16.19:00:00 899 mbufs in use: 668 mbufs allocated to data
16.19:10:00 899 mbufs in use: 668 mbufs allocated to data
16.19:20:00 898 mbufs in use: 668 mbufs allocated to data
16.19:30:00 898 mbufs in use: 668 mbufs allocated to data
16.19:40:01 898 mbufs in use: 668 mbufs allocated to data
16.19:50:00 898 mbufs in use: 668 mbufs allocated to data
16.20:00:00 898 mbufs in use: 668 mbufs allocated to data
16.20:10:00 898 mbufs in use: 668 mbufs allocated to data
16.20:20:00 898 mbufs in use: 668 mbufs allocated to data
16.20:30:00 466 mbufs in use: 455 mbufs allocated to data
16.20:40:00 537 mbufs in use: 526 mbufs allocated to data
16.20:50:01 1017 mbufs in use: 986 mbufs allocated to data
16.21:00:00 1465 mbufs in use: 1428 mbufs allocated to data
16.21:10:00 1496 mbufs in use: 1456 mbufs allocated to data
16.21:20:00 1561 mbufs in use: 1516 mbufs allocated to data
16.21:30:00 1320 mbufs in use: 1278 mbufs allocated to data
16.21:40:00 1391 mbufs in use: 1349 mbufs allocated to data
16.21:50:00 1220 mbufs in use: 1174 mbufs allocated to data
16.22:00:00 945 mbufs in use: 889 mbufs allocated to data
16.22:10:00 914 mbufs in use: 872 mbufs allocated to data
16.22:20:01 1381 mbufs in use: 1334 mbufs allocated to data
16.22:30:00 1553 mbufs in use: 1499 mbufs allocated to data
16.22:40:00 2198 mbufs in use: 2142 mbufs allocated to data
16.22:50:00 1546 mbufs in use: 1491 mbufs allocated to data
16.23:00:01 1097 mbufs in use: 1040 mbufs allocated to data
16.23:10:00 399 mbufs in use: 335 mbufs allocated to data
16.23:20:00 1343 mbufs in use: 1283 mbufs allocated to data
16.23:30:00 2071 mbufs in use: 2013 mbufs allocated to data
16.23:40:00 1539 mbufs in use: 1482 mbufs allocated to data
16.23:50:00 2160 mbufs in use: 2101 mbufs allocated to data
17.00:00:01 1318 mbufs in use: 1263 mbufs allocated to data
17.00:10:01 1463 mbufs in use: 1415 mbufs allocated to data
17.00:20:01 1761 mbufs in use: 1712 mbufs allocated to data
17.00:30:00 1686 mbufs in use: 1630 mbufs allocated to data
17.00:40:00 1104 mbufs in use: 1064 mbufs allocated to data
17.00:50:00 1287 mbufs in use: 1246 mbufs allocated to data