From owner-freebsd-wireless@FreeBSD.ORG Fri Dec 19 16:13:28 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 2ABCF882; Fri, 19 Dec 2014 16:13:28 +0000 (UTC) Received: from mail-wi0-x236.google.com (mail-wi0-x236.google.com [IPv6:2a00:1450:400c:c05::236]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id A63921587; Fri, 19 Dec 2014 16:13:27 +0000 (UTC) Received: by mail-wi0-f182.google.com with SMTP id h11so2298133wiw.3; Fri, 19 Dec 2014 08:13:26 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:sender:in-reply-to:references:date:message-id:subject :from:to:cc:content-type:content-transfer-encoding; bh=SMGIQubAEK/nAjMAgQWJsv1+9gde+zNgCKy8zJ0avuk=; b=Z3NtBBfWk0Cry1bP5nqwLEhjs5gppnUzZOMdkVc/hswRCUbItHqGDEe4YjO7wJKgCY z+ayJjdixP+bFXOar9tfQEgDCYwClLQXA5vWZqra2aBCVYP9BEnHTlvigqbnoDo3rR4q tS1cfglfGIaDB9Tq/VbIdBQy1mBRR65+pEt2OAlmSKHUf0agrt22UiLMAKOjFS1cR92m xWq2S10a+8x80Py2ZczGPaRPVzEb+6GhskumckAN2vJoH7ANjrk9rj0AR8E2KaZt1EBc toOktfzmVuNoHEZBToMK/0fY/GdFxtRzBqTdB3QxUbsQzIGAFGyzAExwBLWMR9p0v68i y3lg== MIME-Version: 1.0 X-Received: by 10.180.20.6 with SMTP id j6mr6975241wie.59.1419005606056; Fri, 19 Dec 2014 08:13:26 -0800 (PST) Sender: adrian.chadd@gmail.com Received: by 10.216.106.195 with HTTP; Fri, 19 Dec 2014 08:13:25 -0800 (PST) In-Reply-To: <20141219075339.GA1748@unixarea.DDR.dd> 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> <20141219075339.GA1748@unixarea.DDR.dd> Date: Fri, 19 Dec 2014 08:13:25 -0800 X-Google-Sender-Auth: _h_o76oCmEKRNOK0zai2r9nUJFg Message-ID: Subject: Re: Issues with urtwn From: Adrian Chadd To: Matthias Apitz Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable 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 16:13:28 -0000 Right, it's going into "stopped" mode, rather than "completed". It's expecting there to be something that'll take the VAP out of power save state, but nothing ever happens to do so. ok. I think I have enough information to track down a fix. Thanks! -adrian On 18 December 2014 at 23:53, Matthias Apitz wrote: > El d=C3=ADa Wednesday, December 17, 2014 a las 06:58:09PM -0800, Adrian C= hadd escribi=C3=B3: > >> ... >> 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_sca= n_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 ava= ilable > 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 negotiatio= n completed with 00:26:0b:4b:b8:44 [PTK=3DCCMP GTK=3DCCMP] > Dec 19 07:41:24 unixarea wpa_supplicant[1731]: wlan0: CTRL-EVENT-CONNECTE= D - Connection to 00:26:0b:4b:b8:44 completed [id=3D2 id_str=3D] > 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.3= 0.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 fro= m > 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, t= icks 2141470 duration 150 > Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: GuruDebug: Enable stat= ion power save mode > Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 1g [act= ive, dwell min 20ms max 150ms] > Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] new probe_resp on ch= an 1 (bss chan 1) "OCLCPublic" rssi 64 > Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] caps 0x431 bintval 1= 00 erp 0x100 country [NL 1-13,23] > Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] new probe_resp on ch= an 1 (bss chan 1) "OCLCPublic" rssi 64 > Dec 19 07:46:24 unixarea kernel: [00:26:0b:4b:b8:44] caps 0x431 bintval 1= 00 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 1= 00 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 [act= ive, dwell min 20ms max 49ms] > Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: stopped, [ticks 214162= 8, dwell min 20 scanend 2141622] > Dec 19 07:46:24 unixarea kernel: wlan0: ieee80211_bg_scan: active scan, t= icks 2141675 duration 150 > Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 11g [act= ive, dwell min 20ms max 150ms] > Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: stopped, [ticks 214184= 0, dwell min 20 scanend 2141825] > Dec 19 07:46:24 unixarea kernel: wlan0: ieee80211_bg_scan: active scan, t= icks 2141880 duration 150 > Dec 19 07:46:24 unixarea kernel: wlan0: scan_task: chan 1g -> 7g [act= ive, dwell min 20ms max 150ms] > Dec 19 07:46:25 unixarea kernel: wlan0: scan_task: stopped, [ticks 214204= 6, dwell min 20 scanend 2142030] > > > after this no more traffic can pass the wlan0 interface; its state is: > > > wlan0: flags=3D8843 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=3D29 > 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 C= TS > 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 ov= erflow, drops 1 (size 50) > Dec 19 07:51:01 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 2 (size 50) > Dec 19 07:51:02 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 3 (size 50) > Dec 19 07:51:12 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 4 (size 50) > Dec 19 07:51:15 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 5 (size 50) > Dec 19 07:51:18 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 6 (size 50) > Dec 19 07:51:23 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 7 (size 50) > Dec 19 07:51:24 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, drops 8 (size 50) > Dec 19 07:51:25 unixarea kernel: wlan0: [00:26:0b:4b:b8:44] pwr save q ov= erflow, 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 zie= hen.