From owner-freebsd-wireless@FreeBSD.ORG Fri Dec 19 07:53:54 2014 Return-Path: Delivered-To: freebsd-wireless@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 72DFF5CF; Fri, 19 Dec 2014 07:53:54 +0000 (UTC) Received: from ms-10.1blu.de (ms-10.1blu.de [178.254.4.101]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 27FB51F40; Fri, 19 Dec 2014 07:53:53 +0000 (UTC) Received: from [89.204.138.167] (helo=unixarea.DDR.dd) by ms-10.1blu.de with esmtpsa (TLS1.0:DHE_RSA_AES_256_CBC_SHA1:32) (Exim 4.76) (envelope-from ) id 1Y1sNh-0002b9-Fi; Fri, 19 Dec 2014 08:53:50 +0100 Received: from unixarea.DDR.dd (localhost [127.0.0.1]) by unixarea.DDR.dd (8.14.9/8.14.3) with ESMTP id sBJ7rgrf001759; Fri, 19 Dec 2014 08:53:43 +0100 (CET) (envelope-from guru@unixarea.de) Received: (from guru@localhost) by unixarea.DDR.dd (8.14.9/8.14.3/Submit) id sBJ7reWj001758; Fri, 19 Dec 2014 08:53:40 +0100 (CET) (envelope-from guru@unixarea.de) X-Authentication-Warning: unixarea.DDR.dd: guru set sender to guru@unixarea.de using -f Date: Fri, 19 Dec 2014 08:53:39 +0100 From: Matthias Apitz To: Adrian Chadd Subject: Re: Issues with urtwn Message-ID: <20141219075339.GA1748@unixarea.DDR.dd> Reply-To: Matthias Apitz References: <20141102084605.GA60031@unixarea.DDR.dd> <54564C92.8040104@freebsd.org> <20141102152953.GA20263@unixarea.DDR.dd> <54564E4D.4020703@freebsd.org> <20141103054633.GA3258@unixarea.DDR.dd> <20141103095530.GA42402@unixarea.DDR.dd> <20141123163811.GA5739@unixarea.DDR.dd> MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: X-Operating-System: FreeBSD 11.0-CURRENT r269739 (i386) User-Agent: Mutt/1.5.23 (2014-03-12) X-Con-Id: 51246 X-Con-U: 0-guru X-Originating-IP: 89.204.138.167 Cc: "freebsd-wireless@freebsd.org" , Nathan Whitehorn X-BeenThere: freebsd-wireless@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: "Discussions of 802.11 stack, tools device driver development." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 19 Dec 2014 07:53:54 -0000 El día Wednesday, December 17, 2014 a las 06:58:09PM -0800, Adrian Chadd escribió: > ... > Would someone please try this again, but run it with scan debugging > enabled (wlandebug +scan) ? The scan_task() routine has some useful > debugging just before it may wake up the VAP; I'd like to see what > that says (whether it says "done" or "stopped" in it.) > ... > Hi, Here comes the messages from such 'wlandebug +scan'; please let me know if you need more tests/logs: ... Dec 19 07:41:24 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] ieee80211_scan_assoc_success Dec 19 07:41:24 unixarea kernel: wlan0: link state changed to UP Dec 19 07:41:24 unixarea dhclient[1828]: send_packet: No buffer space available Dec 19 07:41:24 unixarea wpa_supplicant[1731]: wlan0: Associated with 00:26:0b:4b:b8:44 Dec 19 07:41:24 unixarea wpa_supplicant[1731]: wlan0: WPA: Key negotiation completed with 00:26:0b:4b:b8:44 [PTK=CCMP GTK=CCMP] Dec 19 07:41:24 unixarea wpa_supplicant[1731]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:26:0b:4b:b8:44 completed [id=2 id_str=] Dec 19 07:41:31 unixarea dhclient: New IP Address (wlan0): 10.49.30.104 Dec 19 07:41:31 unixarea dhclient: New Subnet Mask (wlan0): 255.255.255.0 Dec 19 07:41:31 unixarea dhclient: New Broadcast Address (wlan0): 10.49.30.255 Dec 19 07:41:31 unixarea dhclient: New Routers (wlan0): 10.49.30.1 I run in another terminal a cycle of a proc fetching a file with WGET from some sever; the lines are from ipmon for every WGET: Dec 19 07:41:47 unixarea ipmon[508]: 07:41:47.581028 wlan0 @0:14 p 10.49.30.104,37367 -> 132.174.1.212,80 PR tcp len 20 60 -S K-S OUT Dec 19 07:41:50 unixarea ipmon[508]: 07:41:50.803714 wlan0 @0:14 p 10.49.30.104,52814 -> 132.174.1.212,80 PR tcp len 20 60 -S K-S OUT Dec 19 07:41:53 unixarea ipmon[508]: 07:41:53.206811 wlan0 @0:14 p 10.49.30.104,53615 -> 132.174.1.212,80 PR tcp len 20 60 -S K-S OUT Dec 19 07:41:55 unixarea ipmon[508]: 07:41:55.872432 wlan0 @0:14 p 10.49.30.104,55755 -> 132.174.1.212,80 PR tcp len 20 60 -S K-S OUT ... Dec 19 07:46:23 unixarea ipmon[508]: 07:46:23.463618 wlan0 @0:14 p 10.49.30.104,46622 -> 132.174.1.212,80 PR tcp len 20 60 -S K-S OUT now the 300 sec bgscan intervall is over and the bgscan occurs: Dec 19 07:46:24 unixarea kernel: wlan0: ieee80211_bg_scan: active scan, ticks 2141470 duration 150 Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: GuruDebug: Enable station power save mode Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 1g [active, dwell min 20ms max 150ms] Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] new probe_resp on chan 1 (bss chan 1) "OCLCPublic" rssi 64 Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] caps 0x431 bintval 100 erp 0x100 country [NL 1-13,23] Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] new probe_resp on chan 1 (bss chan 1) "OCLCPublic" rssi 64 Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] caps 0x431 bintval 100 erp 0x100 country [NL 1-13,23] Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] new beacon on chan 1 (bss chan 1) "OCLCPublic" rssi 64 Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] caps 0x431 bintval 100 erp 0x100 country [NL 1-13,23] Dec 19 07:46:24 unixarea kernel: wlan0: ieee80211_add_scan: chan 1g min dwell met (2141573 > 2141495) Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 6g [active, dwell min 20ms max 49ms] Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: stopped, [ticks 2141628, dwell min 20 scanend 2141622] Dec 19 07:46:24 unixarea kernel: wlan0: ieee80211_bg_scan: active scan, ticks 2141675 duration 150 Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 11g [active, dwell min 20ms max 150ms] Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: stopped, [ticks 2141840, dwell min 20 scanend 2141825] Dec 19 07:46:24 unixarea kernel: wlan0: ieee80211_bg_scan: active scan, ticks 2141880 duration 150 Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 7g [active, dwell min 20ms max 150ms] Dec 19 07:46:25 unixarea kernel: wlan0: scan_task: stopped, [ticks 2142046, dwell min 20 scanend 2142030] after this no more traffic can pass the wlan0 interface; its state is: wlan0: flags=8843 metric 0 mtu 1500 ether 80:1f:02:ee:16:37 inet 10.49.30.104 netmask 0xffffff00 broadcast 10.49.30.255 nd6 options=29 media: IEEE 802.11 Wireless Ethernet OFDM/54Mbps mode 11g status: associated ssid OCLCPublic channel 1 (2412 MHz 11g) bssid 00:26:0b:4b:b8:44 country US authmode WPA2/802.11i privacy ON deftxkey UNDEF AES-CCM 2:128-bit txpower 0 bmiss 7 scanvalid 60 bgscan bgscanintvl 300 bgscanidle 250 roam:rssi 7 roam:rate 5 protmode CTS roaming MANUAL after some more time some pwr save queue flows over: Dec 19 07:50:59 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 1 (size 50) Dec 19 07:51:01 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 2 (size 50) Dec 19 07:51:02 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 3 (size 50) Dec 19 07:51:12 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 4 (size 50) Dec 19 07:51:15 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 5 (size 50) Dec 19 07:51:18 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 6 (size 50) Dec 19 07:51:23 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 7 (size 50) Dec 19 07:51:24 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 8 (size 50) Dec 19 07:51:25 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q overflow, drops 9 (size 50) -- Matthias Apitz, guru@unixarea.de, http://www.unixarea.de/ +49-170-4527211 1989-2014: The Wall was torn down so that we go to war together again. El Muro ha sido derribado para que nos unimos en ir a la guerra otra vez. Diese Grenze wurde aufgehoben damit wir gemeinsam wieder in den Krieg ziehen.