Date: Thu, 08 May 2008 00:42:14 +0300 From: Oleksandr Samoylyk <oleksandr@samoylyk.sumy.ua> To: Julian Elischer <julian@elischer.org> Cc: freebsd-net@freebsd.org Subject: Re: Problems with netgraph Message-ID: <48222236.5090802@samoylyk.sumy.ua> In-Reply-To: <482209E5.7010607@elischer.org> References: <48207C8B.4020509@samoylyk.sumy.ua> <48209BC4.5080602@elischer.org> <20080507040727.GA28983@verio.net> <48215706.8080508@samoylyk.sumy.ua> <4821EF57.9010600@elischer.org> <4821F206.10606@samoylyk.sumy.ua> <482205F7.4010503@elischer.org> <482206EE.2050904@samoylyk.sumy.ua> <482209E5.7010607@elischer.org>
next in thread | previous in thread | raw e-mail | index | archive | help
Julian Elischer wrote: > Oleksandr Samoylyk wrote: >> Julian Elischer wrote: >>> Oleksandr Samoylyk wrote: >>>> Julian Elischer wrote: >>>>> Oleksandr Samoylyk wrote: >>>>>> David DeSimone wrote: >>>>>>> Julian Elischer <julian@elischer.org> wrote: >>>>>>>> unfortunatly I've been totally ignoring this thread because it >>>>>>>> said >>>>>>>> "trouble with em" in the topic.. >>>>>>>> If you'd said "trouble with mpd" then maybe I'd have looked >>>>>>>> earlier.. >>>>>>> >>>>>>> In the poster's defense, the only symptom that started this was this >>>>>>> info from ps: >>>>>>> >>>>>>> PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU >>>>>>> COMMAND >>>>>>> 29 root 1 -68 - 0K 16K CPU5 5 196:41 >>>>>>> 100.00% em0 taskq >>>>>>> >>>>>>> So tracking it down to mpd has been a process of elimination in >>>>>>> figuring >>>>>>> out why packets absorb so much CPU. >>>>>>> >>>>>> >>>>>> Here is a result of profiling: >>>>>> >>>>>> http://lists.freebsd.org/pipermail/freebsd-net/2008-May/017901.html >>>>>> >>>>> >>>>> >>>>> 0.00 0.00 16/1643247 igmp_input [833] >>>>> 0.03 0.01 614/1643247 icmp_input [272] >>>>> 93.07 17.27 1642617/1643247 encap4_input [9] >>>>> [10] 49.8 93.10 17.27 1643247 rip_input [10] >>>>> 14.26 0.88 600796/749987 >>>>> _mtx_lock_sleep [21] >>>>> 0.16 1.70 1643863/1643863 raw_append [93] >>>>> 0.00 0.24 36345/176995 >>>>> _mtx_unlock_sleep >>>>> [114] >>>>> 0.01 0.00 1643863/5117962 jailed [278] >>>>> 0.00 0.00 1292/1843 m_copym [666] >>>>> 0.00 0.00 676/8214484 m_freem [34] >>>>> >>>>> >>>>> >>>>> 50% of time in rip_input??? >>>>> >>>>> that's unexpected.. what is the traffic? >>>> >>>> >>>> more than 20k pps >>> >>> I mean, what KIND of traffic? >>> I'm surprised it 's calling rip_input().. why is it calling >>> encap4_input()? (which calls rip_input).. what is the IP protocol >>> of all these packets? >>> >>> what does a small snippet of traffic show? >>> >>> (tcpdump -i em0 -s0 -e -n -c 64) >> >> >> GRE (pptp-tunnels) >> >> tcpdump -i em0 -s0 -e -n -c 64 >> >> 22:43:28.818558 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 250: 10.0.0.8.22 > 10.0.14.191.3513: P >> 3482978131:3482978327(196) ack 537019550 win 128 >> 22:43:28.818892 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.113.178: GREv1, call 256, seq >> 949074, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 89.252.42.44.40002 > 77.120.207.229.3038: . 588169704:588171064(1360) >> ack 239105401 win 58593 >> 22:43:28.819014 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.34.188: GREv1, call 0, seq >> 28109460, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 195.91.147.100.62073 > 77.120.205.18.43463: . >> 2979675127:2979676487(1360) ack 3166103641 win 65212 >> 22:43:28.819016 00:11:92:c5:a7:40 > 00:19:d1:03:ce:7e, ethertype IPv4 >> (0x0800), length 111: 10.0.197.49 > 10.0.0.8: GREv1, call 39317, seq >> 1841830, ack 2346966, proto PPP (0x880b), length 77: IP (0x0021), >> length 61: 77.120.205.65.1109 > 89.254.129.137.63441: . ack 2160932834 >> win 17680 <nop,nop,sack 2 {6801:8161}{4081:5441}> >> 22:43:28.819025 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.113.178: GREv1, call 256, seq >> 949075, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 89.252.42.44.40002 > 77.120.207.229.3038: . 1360:2720(1360) ack 1 win >> 58593 >> 22:43:28.819109 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 46: 10.0.0.8 > 10.0.197.49: GREv1, call 16384, ack >> 1841830, no-payload, proto PPP (0x880b), length 12 >> 22:43:28.819152 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.7.198: GREv1, call 32768, seq >> 2854449, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 88.81.240.172.80 > 77.120.206.140.3573: . 2985100912:2985102272(1360) >> ack 3056545326 win 32254 >> 22:43:28.819259 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.34.188: GREv1, call 0, seq >> 28109461, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 195.91.147.100.62073 > 77.120.205.18.43463: . 1360:2720(1360) ack 1 >> win 65212 >> 22:43:28.819632 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 87: 10.0.0.8 > 10.0.3.36: GREv1, call 33358, seq >> 809410, proto PPP (0x880b), length 53: IP (0x0021), length 41: >> 89.189.135.94.29934 > 77.120.205.175.64039: . ack 980726719 win 65535 >> 22:43:28.820102 00:11:92:c5:a7:40 > 00:19:d1:03:ce:7e, ethertype IPv4 >> (0x0800), length 91: 10.0.7.198 > 10.0.0.8: GREv1, call 42872, seq >> 1687270, ack 2854449, proto PPP (0x880b), length 57: IP (0x0021), >> length 41: 77.120.206.140.3573 > 88.81.240.172.80: . ack 1360 win 65535 >> 22:43:28.820172 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 46: 10.0.0.8 > 10.0.7.198: GREv1, call 32768, ack >> 1687270, no-payload, proto PPP (0x880b), length 12 >> 22:43:28.820255 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 461: 10.0.0.8 > 10.0.7.198: GREv1, call 32768, seq >> 2854450, proto PPP (0x880b), length 427: IP (0x0021), length 415: >> 88.81.240.172.80 > 77.120.206.140.3573: . 1360:1734(374) ack 1 win 32254 >> 22:43:28.820382 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.42.36: GREv1, call 16384, seq >> 3749540, proto PPP (0x880b), length 1413: MLPPP (0x003d), length 1401: >> seq 0x039, Flags [begin], length 1400 >> 22:43:28.820386 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 56: 10.0.0.8 > 10.0.42.36: GREv1, call 16384, seq >> 3749541, proto PPP (0x880b), length 22: MLPPP (0x003d), length 10: seq >> 0x039, Flags [end], length 9 >> 22:43:28.820510 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 259: 10.0.0.8 > 10.0.166.29: GREv1, call 256, seq >> 18113, proto PPP (0x880b), length 225: IP (0x0021), length 213: >> 205.188.248.197.80 > 77.120.205.253.1192: P 298024346:298024518(172) >> ack 1774495680 win 16384 >> 22:43:28.820514 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 87: 10.0.0.8 > 10.0.141.78: GREv1, call 32768, seq >> 51008, proto PPP (0x880b), length 53: IP (0x0021), length 41: >> 67.228.189.192.80 > 77.120.207.6.3857: F 98423782:98423782(0) ack >> 337838744 win 6970 >> 22:43:28.820894 00:11:92:c5:a7:40 > 00:19:d1:03:ce:7e, ethertype IPv4 >> (0x0800), length 1451: 10.0.162.204 > 10.0.0.8: GREv1, call 41673, seq >> 145663, ack 88392, proto PPP (0x880b), length 1417: IP (0x0021), >> length 1401: 77.120.206.128.3591 > 89.178.5.14.22979: . >> 2176487112:2176488472(1360) ack 921656808 win 16446 >> 22:43:28.820972 00:11:92:c5:a7:40 > 00:19:d1:03:ce:7e, ethertype IPv4 >> (0x0800), length 1447: 10.0.162.204 > 10.0.0.8: GREv1, call 41673, seq >> 145664, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 77.120.206.128.3591 > 89.178.5.14.22979: . 1360:2720(1360) ack 1 win >> 16446 >> 22:43:28.821014 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 46: 10.0.0.8 > 10.0.162.204: GREv1, call 256, ack >> 145663, no-payload, proto PPP (0x880b), length 12 >> 22:43:28.821020 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.4.108: GREv1, call 32768, seq >> 39341, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 80.93.56.145.80 > 77.120.206.211.3811: . 1861143175:1861144535(1360) >> ack 1545362008 win 65535 >> 22:43:28.821068 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 46: 10.0.0.8 > 10.0.162.204: GREv1, call 256, ack >> 145664, no-payload, proto PPP (0x880b), length 12 >> 22:43:28.821134 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 1447: 10.0.0.8 > 10.0.4.108: GREv1, call 32768, seq >> 39342, proto PPP (0x880b), length 1413: IP (0x0021), length 1401: >> 80.93.56.145.80 > 77.120.206.211.3811: . 1360:2720(1360) ack 1 win 65535 >> 22:43:28.821264 00:19:d1:03:ce:7e > 00:12:cf:53:61:30, ethertype IPv4 >> (0x0800), length 99: 10.0.0.8 > 10.0.75.234: GREv1, call 16384, seq >> 414573, proto PPP (0x880b), length 65: IP (0x0021), length 53: >> 201.246.146.143.55045 > 77.120.205.245.53009: . ack 1074482170 win >> 32502 <nop,nop,timestamp 103973525 28967> >> 22:43:28.821593 00:11:92:c5:a7:40 > 00:19:d1:03:ce:7e, ethertype IPv4 >> (0x0800), length 106: 10.0.163.116 > 10.0.0.8: GREv1, call 46363, seq >> 165235, ack 106705, proto PPP (0x880b), length 72: IP (0x0021), length >> 56: 77.120.206.91.27005 > 194.50.85.251.27017: UDP, length 27 >> 22:43:28.821670 00:19:55:d0:df:c0 > 00:19:d1:03:ce:7e, ethertype IPv4 >> (0x0800), length 60: 10.0.14.191.3513 > 10.0.0.8.22: . ack 196 win 64240 >> >>>> >>>>> I see no netgraph in the profile at all. >>>>> did you statically compile it all in at compile time? (you should >>>>> if you want to see it) >>>>> >>>> >>>> Tried both variants. Now not statically. >>> >>> make sure it is static and that the netgraph nodes are all compiled >>> with -pg >>> >> >> I'll try, but a bit later. > > ok so we get somewhere.. GRE.. > > looks like UDP in PPP in GRE > > is this a pptp session? Yes. > this may be the issue: > http://www.nabble.com/GRE-Mux-td16201899.html > I think so. Should we hope for some progress in this direction in future? -- Oleksandr Samoylyk OVS-RIPE
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?48222236.5090802>