Navigation
High CPU utilization
Tue, 11/24/2009 - 01:13 — Albe
I configured Coovachilli 1.0.14 under Openwrt Kamikaze 8.09 trunk build 18292 with AR2315 based hardware.
It works very well, except the fact it uses a lot of cpu:
looking at top, /usr/sbin/chilli uses 50%-60% CPU with NO clients associated (mainly sys time). With 2 clients it goes up to 95%-100% (both sys time and sirq time).
Do you experience the same high CPU utilization?
Are you using the macauth
Are you using the macauth option? I think so... What you are seeing is chilli ignoring the first DHCP discovery (because it sent a MAC auth request which may return with a Framed-IP-Address explicit assignment of IP address) and waiting for the client to re-ask. In subversion, there is now the option for "strictmacauth" which will keep this functionality, but the default will now be for chilli to go ahead and reply with an IP from it's pool.
Not using macauth
I am not using macauth, but uam login. I use the same configuration file for the 1.0.14 and 1.0.13 (that does not show this problem, like rev. 251 too).
From my log it was not clear that the delay starts AFTER chilli prints "chilli.c: 2970: 0 (Debug) Client MAC=xx-xx-xx-xx-xx-xx assigned IP 192.168.182.2" (i.e. until the printing of the following log lines, in wireshark I can only see the first DHCP Discovery), so it seems that IP address is assigned (or reserved, I suppose) in response of the first DHCP Discovery.
I am trying to investigate further... any other idea/hint?
Slow DHCP problem SOLVED
It was caused by assign_snat() that returns 0 even when uamanyip is not defined or it is 0, so it was blocking further execution.
Here is the patch for 1.0.14.
Index: src/chilli.c
===================================================================
--- src/chilli.c (revisione 208)
+++ src/chilli.c (copia locale)
@@ -2975,7 +2975,7 @@
appconn->uplink = ipm;
ipm->peer = appconn;
- if (!assign_snat(appconn)) {
+ if (!assign_snat(appconn) && options()->uamanyip) {
return -1;
}
}
thanks, but could you try the
thanks, but could you try the subversion code ?
http://www.coova.org/CoovaChilli/Developers
here is a recent dist tarball
http://ap.coova.org/chilli/coova-chilli-1.0.15-pre1.tar.gz
Update and optimization...
I tried 1.0.14 with the stable Kamikaze 8.09.1 and this problem does not show. With no clients associated CPU utilization is 0-1%, as expected.
However maximum bandwidth is about 4,5Mbit/s at 100% CPU utilization, while the maximum network transfer that openwrt can handle is around 14Mb/s.
I wonder if Coovachilli can be optimized for low CPU powered devices (removing some not-basic functions like eapol too)...
We have done a lot of work to
We have done a lot of work to speed up chilli... but, ultimately the bottleneck if the copying to/from kernel space to user space. In the current development version, there are fewer copies, but the ultimate would be to get portions of chilli into a kernel module -- so that at least authenticated traffic can pass through the router un-copied.
Some test bed results
Thanks David for your answer,
I believe you have already done a lot of optimization and now I understand the real bottleneck is the TUN/TAP (it seems that a Xeon 550Mhz can not exceed 55Mbit/s with 100% CPU utilization).
Having Coova-chilli into a kernel module would surely be a very effective solution.
I want to share some performance results obtained with my test bed (Openwrt 8.09.2 or Trunk b18718 - AR2315 MIPS 4KEc 180Mhz CPU):
PC1 (iperf client) -------- Wireless -------- [ AP ] ------------ LAN ----------- PC2 (iperf server)
Measured: Throughput and DHCP time needed by PC1 in order to obtain the lease
RESULTS:
Coova-chilli v. 1.0.12: 4,89 Mbit/s - DHCP time: typical 7 sec, min 5 sec, max 16 sec
Coova-chilli v. 1.0.13: 4,88 Mbit/s - DHCP time: typical 7 sec, min 5 sec, max 16 sec
Coova-chilli v. 1.0.14: 4,80 Mbit/s - DHCP time: typical 10 sec, min 8 sec, max 21 sec
Chillispot v. 1.1: 4,92 Mbit/s - DHCP time: typical 5 sec, min 5 sec, max 8 sec
Coova-chilli SVN Dev (rev. 251): 5,05 Mbit/s - DHCP time: typical 5 sec, min 5 sec, max 17 sec
Coova-chilli SVN Dev (rev. 251 configured with --disable-json --disable-chillixml --disable-ieee8021q --disable-chilliproxy --disable-miniportal --disable-rtmon --disable-ewtapi --disable-netnat): 5,05 Mbit/s - DHCP time: typical 4 sec, min 4 sec, max 17 sec
OBSERVATIONS:
1. As expected, throughput performance is very similar though the different versions, confirming the fact that the bottleneck is the TUN/TAP
2. v. 1.0.14 is less efficient with DHCP than other versions (10 seconds, up to 21 a lot of times)
3. v. 1.0.14 and Rev. 251 have this problem with trunk openwrt (tested on the latest build 18718, too) but:
3.1. They work correctly with the stable 8.09.2
3.2. Rev. 251 works correctly with the trunk 18718 if compiled with "--disable-json --disable-chillixml --disable-ieee8021q --disable-chilliproxy --disable-miniportal --disable-rtmon --disable-ewtapi --disable-netnat"
About OBSERVATION 2...
Digging with Wireshark I found that high DHCP time of v. 1.0.14 is caused by a lock after the first DHCP Discover (8 seconds lost just after the first DHCP request).
I think this problem has been fixed in the latest development release, as it seems to work fine, but if it did not...
Please let me know.
COOVACHILLI 1.0.14 capture
No. Time Source Destination Protocol Info1 0.000000 0.0.0.0 255.255.255.255 DHCP DHCP Discover - Transaction ID 0xa42fe36
2 7.998662 0.0.0.0 255.255.255.255 DHCP DHCP Discover - Transaction ID 0xa42fe36
3 8.004831 192.168.182.1 192.168.182.2 DHCP DHCP Offer - Transaction ID 0xa42fe36
4 8.012652 0.0.0.0 255.255.255.255 DHCP DHCP Request - Transaction ID 0xa42fe36
5 8.111192 192.168.182.1 192.168.182.2 DHCP DHCP ACK - Transaction ID 0xa42fe36
COOVACHILLI 1.0.13 capture
No. Time Source Destination Protocol Info1 0.000000 0.0.0.0 255.255.255.255 DHCP DHCP Discover - Transaction ID 0x82203465
2 0.008210 192.168.182.1 192.168.182.2 DHCP DHCP Offer - Transaction ID 0x82203465
3 0.008502 0.0.0.0 255.255.255.255 DHCP DHCP Request - Transaction ID 0x82203465
4 0.020539 192.168.182.1 192.168.182.2 DHCP DHCP ACK - Transaction ID 0x82203465
COOVACHILLI 1.0.14 log in debug mode (my MAC address hided):
...<---- HERE THE 8 seconds DELAY BEGINSdhcp.c: 2215: 0 (Debug) dhcp_decaps: src=xx:xx:xx:xx:xx:xx dst=ff:ff:ff:ff:ff:ff prot=0006
dhcp.c: 2222: 0 (Debug) Layer2 PROT: 0x0006 dropped
dhcp.c: 2215: 0 (Debug) dhcp_decaps: src=xx:xx:xx:xx:xx:xx dst=ff:ff:ff:ff:ff:ff prot=0006
dhcp.c: 2222: 0 (Debug) Layer2 PROT: 0x0006 dropped
dhcp.c: 2215: 0 (Debug) dhcp_decaps: src=xx:xx:xx:xx:xx:xx dst=ff:ff:ff:ff:ff:ff prot=0800
dhcp.c: 2054: 0 (Debug) dhcp/bootps request being processed
dhcp.c: 326: 0 (Debug) DHCP newconn: xx:xx:xx:xx:xx:xx
chilli.c: 3007: 0 (Debug) New DHCP request from MAC=xx-xx-xx-xx-xx-xx
chilli.c: 3010: 0 (Debug) New DHCP connection established
chilli.c: 2882: 0 (Debug) DHCP request for IP address
ippool.c: 334: 0 (Debug) Requesting new static ip: 0.0.0.0
ippool.c: 334: 0 (Debug) Requesting new dynamic ip: 0.0.0.0
chilli.c: 2970: 0 (Debug) Client MAC=xx-xx-xx-xx-xx-xx assigned IP 192.168.182.2
chilli.c: 3545: 0 (Debug) Processing cmdsock request...dhcp.c: 2215: 0 (Debug) dhcp_decaps: src=xx:xx:xx:xx:xx:xx dst=ff:ff:ff:ff:ff:ff prot=0800dhcp.c: 2054: 0 (Debug) dhcp/bootps request being processed
chilli.c: 2882: 0 (Debug) DHCP request for IP address
dhcp.c: 1374: 0 (Debug) !!! dhcp server : !!!
dhcp.c: 2215: 0 (Debug) dhcp_decaps: src=xx:xx:xx:xx:xx:xx dst=ff:ff:ff:ff:ff:ff prot=0800
dhcp.c: 2054: 0 (Debug) dhcp/bootps request being processed
dhcp.c: 1374: 0 (Debug) !!! dhcp server : !!!
...