From mboxrd@z Thu Jan 1 00:00:00 1970 From: Arkh4mKn1ght Date: Thu, 22 May 2014 21:50:14 -0300 Subject: [ath9k-devel] Weird Atheros 9485 http connecting problems In-Reply-To: References: <5375477C.7050503@gmail.com> <20140516090559.GA5098@qca.qualcomm.com> <537602EB.9000602@gmail.com> <53795054.4050701@gmail.com> <20140519062926.GA18863@qca.qualcomm.com> <537A0346.4090300@gmail.com> <20140519144232.GA19244@qca.qualcomm.com> <537CBA30.80407@gmail.com> <20140521145902.GB9563@qca.qualcomm.com> <537CC1EB.3090500@gmail.com> Message-ID: <537E9B46.8000806@gmail.com> List-Id: MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit To: ath9k-devel@lists.ath9k.org Ok new update. I tested the laptop without using hibernation and the problem happened again after 9 hours of having powered on the machine. Again ASPM disabled on both the root complex and atheros card + powersave mode off. This time i decided to use a script to reload the ath9k modules and restart the connection after the problem happened, which it didnt work, but i got a nasty module call trace in /var/log/messages when i executed it. the script is this: #!/bin/bash modprobe -r ath9k ps -ef | grep wpa_supplicant | awk '{print $2}' | xargs kill -9 ps -ef | grep ifplugd | grep wlan | awk '{print $2}' | xargs kill -9 service network stop sleep 5 service network start the module call trace is this: May 22 21:24:42 localhost kernel: Loading modules backported from Linux version v3.15-rc1-0-gc9eaa44 May 22 21:24:42 localhost kernel: Backport generated by backports.git v3.15-rc1-1-0-g2a25483 May 22 21:24:42 localhost kernel: cfg80211: Calling CRDA to update world regulatory domain May 22 21:24:42 localhost kernel: cfg80211: World regulatory domain updated: May 22 21:24:42 localhost kernel: cfg80211: DFS Master region: unset May 22 21:24:42 localhost kernel: cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time) May 22 21:24:42 localhost kernel: cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: Calling CRDA for country: UY May 22 21:24:42 localhost kernel: cfg80211: Regulatory domain changed to country: UY May 22 21:24:42 localhost kernel: cfg80211: DFS Master region: unset May 22 21:24:42 localhost kernel: cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time) May 22 21:24:42 localhost kernel: cfg80211: (2402000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz), (N/A, 1700 mBm), (N/A) May 22 21:24:42 localhost kernel: cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz), (N/A, 2400 mBm), (0 s) May 22 21:24:42 localhost kernel: cfg80211: (5490000 KHz - 5730000 KHz @ 80000 KHz), (N/A, 2400 mBm), (0 s) May 22 21:24:42 localhost kernel: cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 3000 mBm), (N/A) May 22 21:24:42 localhost kernel: ath: phy0: Disable PLL PowerSave May 22 21:24:42 localhost kernel: modprobe: page allocation failure: order:4, mode:0x1040d0 May 22 21:24:42 localhost kernel: CPU: 3 PID: 30011 Comm: modprobe Tainted: G O 3.12.18-desktop-1.mga4 #1 May 22 21:24:42 localhost kernel: Hardware name: Sony Corporation SVE14125CLB/VAIO, BIOS R0150D5 08/30/2012 May 22 21:24:42 localhost kernel: 0000000000000000 ffff88006af35738 ffffffff816116b9 00000000001040d0 May 22 21:24:42 localhost kernel: ffff88006af357c0 ffffffff81132430 000000000000000e ffff88006af35760 May 22 21:24:42 localhost kernel: ffffffff81134ed6 ffff88006af35790 0000000000000286 0000000000000003 May 22 21:24:42 localhost kernel: Call Trace: May 22 21:24:42 localhost kernel: [] dump_stack+0x45/0x56 May 22 21:24:42 localhost kernel: [] warn_alloc_failed+0xf0/0x140 May 22 21:24:42 localhost kernel: [] ? drain_local_pages+0x16/0x20 May 22 21:24:42 localhost kernel: [] __alloc_pages_nodemask+0x862/0xa20 May 22 21:24:42 localhost kernel: [] alloc_pages_current+0xa9/0x160 May 22 21:24:42 localhost kernel: [] __get_free_pages+0xe/0x50 May 22 21:24:42 localhost kernel: [] kmalloc_order_trace+0x2e/0xa0 May 22 21:24:42 localhost kernel: [] __kmalloc_track_caller+0x171/0x180 May 22 21:24:42 localhost kernel: [] ? ath_descdma_setup+0x113/0x390 [ath9k] May 22 21:24:42 localhost kernel: [] devm_kzalloc+0x25/0x70 May 22 21:24:42 localhost kernel: [] ath_descdma_setup+0x113/0x390 [ath9k] May 22 21:24:42 localhost kernel: [] ath_tx_init+0x55/0x1f0 [ath9k] May 22 21:24:42 localhost kernel: [] ath9k_init_device+0xb7e/0xd00 [ath9k] May 22 21:24:42 localhost kernel: [] ? request_threaded_irq+0x82/0x170 May 22 21:24:42 localhost kernel: [] ? ath9k_start+0x220/0x220 [ath9k] May 22 21:24:42 localhost kernel: [] ? request_threaded_irq+0xcc/0x170 May 22 21:24:42 localhost kernel: [] ath_pci_probe+0x235/0x330 [ath9k] May 22 21:24:42 localhost kernel: [] ? sysfs_addrm_finish+0x33/0xc0 May 22 21:24:42 localhost kernel: [] local_pci_probe+0x3e/0x70 May 22 21:24:42 localhost kernel: [] pci_device_probe+0x111/0x120 May 22 21:24:42 localhost kernel: [] driver_probe_device+0x125/0x3b0 May 22 21:24:42 localhost kernel: [] __driver_attach+0x93/0xa0 May 22 21:24:42 localhost kernel: [] ? __device_attach+0x40/0x40 May 22 21:24:42 localhost kernel: [] bus_for_each_dev+0x63/0xa0 May 22 21:24:42 localhost kernel: [] driver_attach+0x1e/0x20 May 22 21:24:42 localhost kernel: [] bus_add_driver+0x200/0x2d0 May 22 21:24:42 localhost kernel: [] ? 0xffffffffa0789fff May 22 21:24:42 localhost kernel: [] driver_register+0x64/0xf0 May 22 21:24:42 localhost kernel: [] ? 0xffffffffa0789fff May 22 21:24:42 localhost kernel: [] __pci_register_driver+0x4b/0x50 May 22 21:24:42 localhost kernel: [] ath_pci_init+0x23/0x30 [ath9k] May 22 21:24:42 localhost kernel: [] __init_backport+0xe/0x1000 [ath9k] May 22 21:24:42 localhost kernel: [] do_one_initcall+0xfa/0x1b0 May 22 21:24:42 localhost kernel: [] ? set_memory_nx+0x43/0x50 May 22 21:24:42 localhost kernel: [] load_module+0x2028/0x2680 May 22 21:24:42 localhost kernel: [] ? store_uevent+0x40/0x40 May 22 21:24:42 localhost kernel: [] SyS_finit_module+0x86/0xb0 May 22 21:24:42 localhost kernel: [] system_call_fastpath+0x1a/0x1f May 22 21:24:42 localhost kernel: Mem-Info: May 22 21:24:42 localhost kernel: Node 0 DMA per-cpu: May 22 21:24:42 localhost kernel: CPU 0: hi: 0, btch: 1 usd: 0 May 22 21:24:42 localhost kernel: CPU 1: hi: 0, btch: 1 usd: 0 May 22 21:24:42 localhost kernel: CPU 2: hi: 0, btch: 1 usd: 0 May 22 21:24:42 localhost kernel: CPU 3: hi: 0, btch: 1 usd: 0 May 22 21:24:42 localhost kernel: Node 0 DMA32 per-cpu: May 22 21:24:42 localhost kernel: CPU 0: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: CPU 1: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: CPU 2: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: CPU 3: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: Node 0 Normal per-cpu: May 22 21:24:42 localhost kernel: CPU 0: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: CPU 1: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: CPU 2: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: CPU 3: hi: 186, btch: 31 usd: 0 May 22 21:24:42 localhost kernel: active_anon:408612 inactive_anon:12325 isolated_anon:0 May 22 21:24:42 localhost kernel: active_file:146977 inactive_file:146933 isolated_file:32 May 22 21:24:42 localhost kernel: unevictable:0 dirty:89 writeback:0 unstable:0 May 22 21:24:42 localhost kernel: free:74668 slab_reclaimable:13917 slab_unreclaimable:8897 May 22 21:24:42 localhost kernel: mapped:285033 shmem:13469 pagetables:7573 bounce:0 May 22 21:24:42 localhost kernel: free_cma:0 May 22 21:24:42 localhost kernel: Node 0 DMA free:15780kB min:268kB low:332kB high:400kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:16kB slab_unreclaimable:16kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes May 22 21:24:42 localhost kernel: lowmem_reserve[]: 0 2687 3886 3886 May 22 21:24:42 localhost kernel: Node 0 DMA32 free:243096kB min:46556kB low:58192kB high:69832kB active_anon:1083608kB inactive_anon:31688kB active_file:432220kB inactive_file:445304kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2833152kB managed:2756436kB mlocked:0kB dirty:236kB writeback:0kB mapped:745224kB shmem:34992kB slab_reclaimable:39528kB slab_unreclaimable:20516kB kernel_stack:2408kB pagetables:19812kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no May 22 21:24:42 localhost kernel: lowmem_reserve[]: 0 0 1198 1198 May 22 21:24:42 localhost kernel: Node 0 Normal free:39796kB min:20756kB low:25944kB high:31132kB active_anon:550840kB inactive_anon:17612kB active_file:155688kB inactive_file:142428kB unevictable:0kB isolated(anon):0kB isolated(file):128kB present:1294336kB managed:1227128kB mlocked:0kB dirty:120kB writeback:0kB mapped:394908kB shmem:18884kB slab_reclaimable:16124kB slab_unreclaimable:15056kB kernel_stack:1448kB pagetables:10480kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:83 all_unreclaimable? no May 22 21:24:42 localhost kernel: lowmem_reserve[]: 0 0 0 0 May 22 21:24:42 localhost kernel: Node 0 DMA: 1*4kB (U) 0*8kB 2*16kB (UE) 2*32kB (UE) 3*64kB (UE) 1*128kB (E) 2*256kB (UE) 1*512kB (E) 2*1024kB (UE) 2*2048kB (ER) 2*4096kB (M) = 15780kB May 22 21:24:42 localhost kernel: Node 0 DMA32: 1000*4kB (UEM) 21105*8kB (UEM) 3819*16kB (UEM) 241*32kB (UEM) 15*64kB (UEM) 6*128kB (U) 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 243384kB May 22 21:24:42 localhost kernel: Node 0 Normal: 7576*4kB (UEM) 782*8kB (UEM) 68*16kB (UEM) 18*32kB (UEM) 16*64kB (UEM) 1*128kB (E) 1*256kB (U) 1*512kB (M) 0*1024kB 0*2048kB 0*4096kB = 40144kB May 22 21:24:42 localhost kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB May 22 21:24:42 localhost kernel: 307383 total pagecache pages May 22 21:24:42 localhost kernel: 0 pages in swap cache May 22 21:24:42 localhost kernel: Swap cache stats: add 0, delete 0, find 0/0 May 22 21:24:42 localhost kernel: Free swap = 0kB May 22 21:24:42 localhost kernel: Total swap = 0kB May 22 21:24:42 localhost kernel: 1035868 pages RAM May 22 21:24:42 localhost kernel: 0 pages HighMem/MovableOnly May 22 21:24:42 localhost kernel: 16802 pages reserved May 22 21:24:42 localhost kernel: ath: phy0: Failed to allocate tx descriptors: -12 May 22 21:24:42 localhost kernel: ath9k 0000:07:00.0: Failed to initialize device May 22 21:24:42 localhost kernel: ath9k: probe of 0000:07:00.0 failed with error -12 In order to make the connection work again i had to reboot the machine... So this log seems to imply three options, a) there is a bug somewhere in the ath9k driver, b) my atheros card is a piece of shit or c) the BIOS of the laptop is a piece of shit.... I dont have any more tests to do besides installing the BIOS update( after installing windows 8 somehow ughhhh..) What do you guys think? Greetings Oskar On 05/21/2014 05:10 PM, Adrian Chadd wrote: > hi, > > Hm. You're hibernating? That may explain why the thing is return > 0xdeadc0de during register reads. Maybe the MAC isn't fully waking up > after a resume? > > > -a > > > On 21 May 2014 08:10, Arkh4mKn1ght wrote: >> Hi rajkumar >> >> I dont know if this only happens when resuming from hibernate, it was just a >> thought that ocurred to me today. I will test again without hibernating to >> see if this happens again. >> I dont use any firewall on the laptop, so iptables -F is pointless. >> Ping latency times are good when the problem is ongoing. >> I will take a sniffer capture and send it back to you. >> >> Thanks for your help >> >> Oskar >> >> >> On 05/21/2014 11:59 AM, Rajkumar Manoharan wrote: >>> On Wed, May 21, 2014 at 11:37:36AM -0300, Arkh4mKn1ght wrote: >>>> Ok i tried the patch but the issue happened again :( >>>> >>>> After resuming my laptop from hibernation i saw in >>>> /var/log/kernel/errors.log these messages again: >>>> >>>> May 21 09:20:10 localhost kernel: mei_me 0000:00:16.0: suspend >>>> May 21 09:20:10 localhost kernel: ath: phy1: RX failed to go idle in 10 >>>> ms >>>> RXSM=0xdeadbeef >>>> May 21 09:20:10 localhost kernel: ath: phy1: DMA failed to stop in 10 ms >>>> AR_CR=0xdeadbeef AR_DIAG_SW=0xdeadbeef DMADBG_7=0xdeadbeef >>>> May 21 09:20:11 localhost kernel: dpm_run_callback(): >>>> usb_dev_restore+0x0/0x20 [usbcore] returns -107 >>>> May 21 09:20:11 localhost kernel: PM: Device 1-1 failed to restore async: >>>> error -107 >>>> >>>> ASPM was disabled on root complex and atheros card.powersave was off. >>>> After 1 hour and 10 minutes of those messages that problem arise. I have >>>> noticed that the problem arises always after some time of resuming the >>>> laptop from hibernation. >>>> >>>> Its really odd, because when it does happen, browsing the web is >>>> painfully >>>> slow with the "connecting to domain.com..." message in the browser status >>>> bar... it does load the website but after some minutes.. >>>> Meanwhile at the same time if i try to download a torrent using a >>>> bittorrent >>>> client i can do it without problems at full speed. If i pause the >>>> torrent, >>>> browsing websites still behaves slowly until i reboot the laptop. >>>> >>>> At first i thought that i have a defective atheros card, but why i can >>>> download torrents at full speed when this problem arises? >>>> What options do i have now? i have tested all combinations of ASPM >>>> enabled/disabled and powersave on/off. >>>> >>>> I have seen that there is a BIOS update for my laptop, but im unsure it >>>> could help for this at all (besides that i would have to install windows >>>> 8 >>>> to install the friggin bios update) >>>> >>> Oskar, >>> >>> I am quite confused. Does the issue happen only after resume from >>> hibernate? >>> Initially you havn't mentioned hibernate/resume. Are you able to >>> reproduce the issue without hibernating? Please flush ip table entries >>> and test. >>> >>> sudo iptables -F >>> >>> Can you please take a sniffer capture at the problematic time? Are you >>> seeing huge >>> latency for ping (icmp)? >>> >>> -Rajkumar >>>