Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

mwifiex 1.0 (16.68.10.p159) - PCIEUSB-8997 firmware is buggy #1

Open
erdoukki opened this issue Jun 28, 2021 · 66 comments
Open

mwifiex 1.0 (16.68.10.p159) - PCIEUSB-8997 firmware is buggy #1

erdoukki opened this issue Jun 28, 2021 · 66 comments

Comments

@erdoukki
Copy link

erdoukki commented Jun 28, 2021 •
edited
Loading

MVEBU - EspressoBin ULTRA wifi - BUGS with OpenWrt 21.02-RC
312ca02

PCIEUSB-8997:
WLAN (PCIE) firmware version: W16.68.10.p159
Bluetooth (USB) firmware version: W16.26.10.p159
The combo image can be downloaded through WLAN only.

Can anyone help with this bug ?
kaloz/mwlwifi#397
https://forum.openwrt.org/t/openwrt-21-02-0-third-release-candidate/99363/32

[    8.880656] mwifiex_pcie 0000:01:00.0: info: FW download over, size 638992 bytes
[    9.723892] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[    9.805987] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.10.p159) 
[    9.814683] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.10.p159)

EDIT:
Hardware used for testing:
EspressoBin-ULTRA from GlobalScaleTechnologies.
Official Product: https://globalscaletechnologies.com/product/espressobin-ultra/
CNX review: https://www.cnx-software.com/2019/12/30/espressobin-ultra-gateway-features-5-gigabit-ethernet-ports-wifi-5-supports-4g-lte-cellular-connectivity/
Block Diagram: http://espressobin.net/wp-content/uploads/2020/05/ESPRESSOBin-Ultra-V1_-Block-diagram_.pdf

OS info (from OpenWrt 21.02.x):

root@ultra:~# uname -ar
Linux ultra 5.4.124 #0 SMP Sun Jun 13 22:02:19 2021 aarch64 GNU/Linux

root@ultra:~# lsusb
Bus 001 Device 003: ID 1286:204e Marvell Bluetooth and Wireless LAN Composite Device

root@ultra:~# dmesg | grep pcie
[    8.838866] mwifiex_pcie: PCI memory map Virt0: 00000000f018cccc PCI memory map Virt2: 00000000726eced0
[   10.169604] mwifiex_pcie 0000:01:00.0: info: FW download over, size 631012 bytes
[   11.034644] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   11.106306] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145) 
[   11.114812] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p145)

EDIT: A summary of my tests here:
#1 (comment)

  • W16.68.10.p159 = KO
  • W16.68.1.p195 = KO
  • V16.68.1.p145 = OK
  • 16.68.1.p140 = OK
  • 16.68.1.p133 = OK
  • 16.68.1.p97 = OK
  • 16.68.1.p70 = KO

Tests (quick tests) made only with ONE AP and TWO CLIENTS on the AP...

Config used :
cat /etc/config/wireless

config wifi-device 'radio0'
	option type 'mac80211'
	option path 'soc/d0070000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0'
	option htmode 'HT20'
	option hwmode '11g'
	option channel 'auto'
	option log_level '1'
	option cell_density '0'
	option country 'FR'
	option legacy_rates '1'

config wifi-iface 'default_radio0'
	option device 'radio0'
	option network 'lan'
	option mode 'ap'
	option ssid 'ACCESSPOINT'
	option key 'PASSWORD'
	option encryption 'psk2'
	option skip_inactivity_poll '1'
@erdoukki
Copy link
Author 

[   11.278496] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1                                                                                                  
[   11.306264] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1                                                                                                  
[   17.913709] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xb1 error, result=0x1                                                                                                  
[   17.920969] mwifiex_pcie 0000:01:00.0: Failed to start the BSS                                                                                                               
[   17.927025] mwifiex_pcie 0000:01:00.0: Failed to start AP                                                                                                                    
[   23.917702] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xb1 error, result=0x1                                                                                                  
[   23.925641] mwifiex_pcie 0000:01:00.0: Failed to start the BSS                                                                                                               
[   23.931672] mwifiex_pcie 0000:01:00.0: Failed to start AP                                                                                                                    
[   29.942278] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xb1 error, result=0x1                                                                                                  
[   29.949971] mwifiex_pcie 0000:01:00.0: Failed to start the BSS                                                                                                               
[   29.956065] mwifiex_pcie 0000:01:00.0: Failed to start AP

@erdoukki
Copy link
Author

https://forum.openwrt.org/t/mwlwifi-and-kernel-5-10/90115/18?u=erdoukki

@erdoukki erdoukki reopened this Aug 4, 2021
@erdoukki
Copy link
Author

erdoukki commented Aug 4, 2021

root@ULTRA-5G:/# uname -ar

Linux ULTRA-5G 5.4.124 #0 SMP Sun Jun 13 22:02:19 2021 aarch64 GNU/Linux

dmesg / logread give :

Wed Aug  4 14:37:02 2021 kern.info kernel: [ 1440.569280] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1

root@ULTRA-5G:~# iw dev
phy#0
	Interface wlan0
		ifindex 20
		wdev 0x1
		addr f0:ad:4e:10:0e:c3
		type AP
		txpower 0.00 dBm

[ 2395.300894] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[ 2453.187918] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[ 2489.210316] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1

@erdoukki
Copy link
Author

erdoukki commented Aug 4, 2021

after a reboot, it may works...

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

It looks like only one client get access successfully...

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

I add two tweaks in my /etc/rc.local :

# WIFI FIXME
uci set wireless.radio0.legacy_rates='1'
uci commit
wifi

# WIFI FIXME
iw wlan0 set power_save off

But I still get problems...
How can I help to analyse, report and fixes this !?

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

ping @sharvari-nxp

@erdoukki erdoukki changed the title Espressobin ultra wifi hang or bug with OpenWrt 21.02-RC MWIFIEX - MVEBU - Espressobin ultra wifi hang or bug with OpenWrt 21.02-RC Aug 6, 2021
@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021 •
edited
Loading 

# WIFI FIXME
uci set wireless.radio0.legacy_rates='1'
uci commit
wifi

This help to make the Access Point visible and available...

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

I have activated the optional verbose debug log on the wifi device : with option log_level '1'

Fri Aug  6 10:58:45 2021 daemon.notice hostapd: wlan0: interface state ACS->ENABLED
Fri Aug  6 10:58:45 2021 daemon.notice hostapd: wlan0: AP-ENABLED
Fri Aug  6 10:58:51 2021 kern.info kernel: [56066.999853] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xb1 error, result=0x1
Fri Aug  6 10:58:51 2021 kern.info kernel: [56067.007152] mwifiex_pcie 0000:01:00.0: Failed to start the BSS
Fri Aug  6 10:58:51 2021 kern.info kernel: [56067.013195] mwifiex_pcie 0000:01:00.0: Failed to start AP
Fri Aug  6 10:58:57 2021 kern.info kernel: [56073.028509] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xb1 error, result=0x1
Fri Aug  6 10:58:57 2021 kern.info kernel: [56073.037282] mwifiex_pcie 0000:01:00.0: Failed to start the BSS
Fri Aug  6 10:58:57 2021 kern.info kernel: [56073.043959] mwifiex_pcie 0000:01:00.0: Failed to start AP

with forcing legacy rates I get it up again :

Fri Aug  6 11:00:24 2021 daemon.notice netifd: Network device 'wlan0' link is up
Fri Aug  6 11:00:24 2021 daemon.notice hostapd: wlan0: interface state ACS->ENABLED
Fri Aug  6 11:00:24 2021 daemon.notice hostapd: wlan0: AP-ENABLED

@erdoukki erdoukki changed the title MWIFIEX - MVEBU - Espressobin ultra wifi hang or bug with OpenWrt 21.02-RC MWIFIEX - MVEBU - EspressoBin ULTRA wifi hang or bug with OpenWrt 21.02-RC Aug 6, 2021
@erdoukki erdoukki changed the title MWIFIEX - MVEBU - EspressoBin ULTRA wifi hang or bug with OpenWrt 21.02-RC MWIFIEX - MVEBU - EspressoBin ULTRA wifi - BUGS with OpenWrt 21.02-RC Aug 6, 2021
@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

Clients may still have issues, like Apples clients (iOS iPAD and iPhone) which get no access to the AP...
With WPA or WPA2 I get errors and without encryption I get no IP...

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

I have add a /etc/modules.d/mwifiex file with the following content :

mwifiex reg_alpha2=FR

root@ULTRA-5G:~# dmesg |grep mwifiex_pcie
[    8.709601] mwifiex_pcie: PCI memory map Virt0: 00000000a3db35c7 PCI memory map Virt2: 000000004005f488
[    9.892557] mwifiex_pcie 0000:01:00.0: info: FW download over, size 638992 bytes
[   10.733601] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   10.791178] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.10.p159) 
[   10.799895] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.10.p159) 
[   16.811868] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   29.661153] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   29.704430] mwifiex_pcie 0000:01:00.0: cannot change wiphy params when bss started
[   30.128058] mwifiex_pcie 0000:01:00.0: cannot register network device

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

I have add a /etc/modules.d/mwifiex file with the following content :

removed... same !

root@ULTRA-5G:~# ethtool -i wlan0
driver: mwifiex_pcie
version: 
firmware-version: 
expansion-rom-version: 
bus-info: 0000:01:00.0
supports-statistics: no
supports-test: no
supports-eeprom-access: no
supports-register-dump: no
supports-priv-flags: no

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

I test it now also by removing wpad and replacing it by hostapd-openssl

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021

I test it now also by removing wpad and replacing it by hostapd-openssl

with forcing legacy rates I get it up again :

# WIFI FIXME
uci set wireless.radio0.legacy_rates='1'
uci commit
wifi

# WIFI FIXME
iw wlan0 set power_save off

added in /etc/rc.local

now I have 4 clients on it...
BUT only without encryption...
If I enable WPA2 I get now only one client again, the others get faulty with dmesg error logged :

[   63.388904] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1
[   63.396413] mwifiex_pcie 0000:01:00.0: crypto keys added
[   64.764481] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1
[   64.771723] mwifiex_pcie 0000:01:00.0: crypto keys added
[   66.169967] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1
[   66.177264] mwifiex_pcie 0000:01:00.0: crypto keys added
[   70.810310] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1
[   70.817755] mwifiex_pcie 0000:01:00.0: crypto keys added
[   75.478474] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1
[   75.485768] mwifiex_pcie 0000:01:00.0: crypto keys added

@erdoukki
Copy link
Author

erdoukki commented Aug 6, 2021 •
edited
Loading

This commit has not the problem :
https://github.com/NXP/mwifiex-firmware/blob/2a0a062e79b5fe9007e57c0fcd285e683e22373e/mrvl/pcieusb8997_combo_v4.bin

wget https://github.com/NXP/mwifiex-firmware/blob/2a0a062e79b5fe9007e57c0fcd285e683e22373e/mrvl/pcieusb8997_combo_v4.bin?raw=true -O /lib/firmware/mrvl/pcieusb8997_combo_v4.bin 
reboot

still added wireless.radio0.legacy_rates='1'

root@ULTRA-5G:~# dmesg | grep mwifiex
[    8.642706] mwifiex_pcie: PCI memory map Virt0: 000000009f690fa7 PCI memory map Virt2: 000000005f0cc217
[    9.816137] mwifiex_pcie 0000:01:00.0: info: FW download over, size 634228 bytes
[   10.662822] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   10.733597] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p195) 
[   10.742080] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p195) 
[   17.831804] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   17.910362] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1
[   30.684304] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   30.749067] mwifiex_pcie 0000:01:00.0: cannot change wiphy params when bss started
[   30.804154] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1
[   31.413758] mwifiex_pcie 0000:01:00.0: cannot register network device

No more crypto keys added error and multi clients on the AP are OK !

@erdoukki
Copy link
Author

erdoukki commented Aug 7, 2021 

root@ULTRA-5G:~# iwinfo wlan1 info
wlan1     ESSID: "TRIBU"
          Access Point: F0:AD:4E:10:0E:C3
          Mode: Master  Channel: 3 (2.422 GHz)
          Center Channel 1: 3 2: unknown
          Tx-Power: 15 dBm  Link Quality: 47/70
          Signal: -63 dBm  Noise: -92 dBm
          Bit Rate: 13.7 MBit/s
          Encryption: WPA2 PSK (CCMP)
          Type: nl80211  HW Mode(s): 802.11nac
          Hardware: 1B4B:2B42 0000:0000 [Generic MAC80211]
          TX power offset: unknown
          Frequency offset: unknown
          Supports VAPs: yes  PHY name: phy1

@erdoukki
Copy link
Author

erdoukki commented Aug 7, 2021 •
edited
Loading 

[75068.549574] mwifiex_pcie 0000:01:00.0: mwifiex_cmd_timeout_func: Timeout cmd id = 0xb0, act = 0x1
[75068.558855] mwifiex_pcie 0000:01:00.0: num_data_h2c_failure = 0
[75068.565095] mwifiex_pcie 0000:01:00.0: num_cmd_h2c_failure = 0
[75068.571156] mwifiex_pcie 0000:01:00.0: is_cmd_timedout = 1
[75068.576825] mwifiex_pcie 0000:01:00.0: num_tx_timeout = 0
[75068.582421] mwifiex_pcie 0000:01:00.0: last_cmd_index = 2
[75068.588000] mwifiex_pcie 0000:01:00.0: last_cmd_id: 5e 00 28 00 b0 00 b0 00 28 00
[75068.595732] mwifiex_pcie 0000:01:00.0: last_cmd_act: 01 00 93 00 01 00 01 00 93 00
[75068.603549] mwifiex_pcie 0000:01:00.0: last_cmd_resp_index = 0
[75068.609573] mwifiex_pcie 0000:01:00.0: last_cmd_resp_id: 28 80 28 80 b0 80 28 80 5e 80
[75068.617739] mwifiex_pcie 0000:01:00.0: last_event_index = 2
[75068.623495] mwifiex_pcie 0000:01:00.0: last_event: 58 00 58 00 2e 00 58 00 58 00
[75068.631131] mwifiex_pcie 0000:01:00.0: data_sent=0 cmd_sent=1
[75068.637058] mwifiex_pcie 0000:01:00.0: ps_mode=0 ps_state=0
[75068.642875] mwifiex_pcie 0000:01:00.0: mwifiex_cfg80211_change_beacon: setting mgmt ies failed
[75068.644294] mwifiex_pcie 0000:01:00.0: ===mwifiex driverinfo dump start===
[75068.658893] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p195) 
[75068.667442] mwifiex_pcie 0000:01:00.0: PCIE register dump start
[75068.673664] mwifiex_pcie 0000:01:00.0: pcie scratch register:
[75068.679650] mwifiex_pcie 0000:01:00.0: reg:0xcf0, value=0xfedcba00
[75068.679650] reg:0xcf8, value=0x2cf004f
[75068.679650] reg:0xcfc, value=0x1444400
[75068.679650] 
[75068.695403] mwifiex_pcie 0000:01:00.0: PCIE register dump end
[75068.701570] mwifiex_pcie 0000:01:00.0: ===mwifiex driverinfo dump end===
[75068.708542] mwifiex_pcie 0000:01:00.0: == mwifiex firmware dump start ==
[75070.231652] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state

...<REPEATED MESSAGE !!!>

[75076.140553] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.147088] device wlan1 left promiscuous mode
[75076.151948] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.158425] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.164956] br-lan: port 5(wlan1) entered disabled state
[75076.214180] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.244726] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.251406] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.257878] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.264426] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.270906] mwifiex_pcie 0000:01:00.0: Failed to delete mgmt IEs!
[75076.277192] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.283673] mwifiex_pcie 0000:01:00.0: Failed to stop the BSS
[75076.296785] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.313438] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.465364] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.635037] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.691620] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.783187] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.838125] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.902265] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.935103] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75076.984124] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75077.681523] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75077.703697] mwifiex_pcie 0000:01:00.0: cannot change wiphy params when bss started
[75077.718672] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75077.754913] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75077.951815] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75077.958295] mwifiex_pcie 0000:01:00.0: set mac address failed: ret=-1
[75077.965030] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.260379] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.412613] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.466307] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.585980] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.649712] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.722286] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.752879] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75081.793620] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75112.171061] mwifiex_pcie 0000:01:00.0: == mwifiex firmware dump end ==
[75112.180811] mwifiex_pcie 0000:01:00.0: == mwifiex dump information to /sys/class/devcoredump start
[75112.190429] mwifiex_pcie 0000:01:00.0: == mwifiex dump information to /sys/class/devcoredump end
[75112.199685] mwifiex_pcie 0000:01:00.0: PREP_CMD: FW is in bad state
[75112.206740] mwifiex_pcie 0000:01:00.0: info: shutdown mwifiex...
[75112.499259] mwifiex_pcie 0000:01:00.0: info: dnld wifi firmware from 177740 bytes
[75113.892508] mwifiex_pcie 0000:01:00.0: info: FW download over, size 634228 bytes
[75114.618970] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[75114.669483] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p195) 
[75114.677955] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p195)

@erdoukki
Copy link
Author

erdoukki commented Aug 7, 2021 

[  434.412893] mwifiex_pcie 0000:01:00.0: mwifiex_cmd_timeout_func: Timeout cmd id = 0x28, act = 0x93                                                                                    
[  434.422232] mwifiex_pcie 0000:01:00.0: num_data_h2c_failure = 0                                                                                                                       
[  434.428488] mwifiex_pcie 0000:01:00.0: num_cmd_h2c_failure = 0                                                                                                                        
[  434.434624] mwifiex_pcie 0000:01:00.0: is_cmd_timedout = 1                                                                                                                            
[  434.440335] mwifiex_pcie 0000:01:00.0: num_tx_timeout = 0                                                                                                                             
[  434.445944] mwifiex_pcie 0000:01:00.0: last_cmd_index = 1                                                                                                                             
[  434.451524] mwifiex_pcie 0000:01:00.0: last_cmd_id: 28 00 28 00 28 00 b0 00 5e 00                                                                                                     
[  434.459267] mwifiex_pcie 0000:01:00.0: last_cmd_act: 93 00 93 00 93 00 01 00 01 00                                                                                                    
[  434.467100] mwifiex_pcie 0000:01:00.0: last_cmd_resp_index = 0                                                                                                                        
[  434.473138] mwifiex_pcie 0000:01:00.0: last_cmd_resp_id: 28 80 b1 80 28 80 b0 80 5e 80                                                                                                
[  434.481315] mwifiex_pcie 0000:01:00.0: last_event_index = 2                                                                                                                           
[  434.487090] mwifiex_pcie 0000:01:00.0: last_event: 2e 00 2c 00 2c 00 58 00 58 00                                                                                                      
[  434.494740] mwifiex_pcie 0000:01:00.0: data_sent=0 cmd_sent=1                                                                                                                         
[  434.500667] mwifiex_pcie 0000:01:00.0: ps_mode=0 ps_state=0                                                                                                                           
[  434.508398] mwifiex_pcie 0000:01:00.0: ===mwifiex driverinfo dump start===                                                                                                            
[  434.515599] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p195)                                                                                              
[  434.524095] mwifiex_pcie 0000:01:00.0: PCIE register dump start                                                                                                                       
[  434.530202] mwifiex_pcie 0000:01:00.0: pcie scratch register:                                                                                                                         
[  434.536161] mwifiex_pcie 0000:01:00.0: reg:0xcf0, value=0xfedcba00                                                                                                                    
[  434.536161] reg:0xcf8, value=0x224004f                                                                                                                                                
[  434.536161] reg:0xcfc, value=0x1b6b620                                                                                                                                                
[  434.536161]                                                                                                                                                                           
[  434.551775] mwifiex_pcie 0000:01:00.0: PCIE register dump end                                                                                                                         
[  434.557805] mwifiex_pcie 0000:01:00.0: ===mwifiex driverinfo dump end===                                                                                                              
[  434.564728] mwifiex_pcie 0000:01:00.0: == mwifiex firmware dump start ==                                                                                                              
[  440.812993] mwifiex_pcie 0000:01:00.0: cmd_wait_q terminated: -110                                                                                                                    
[  440.819535] mwifiex_pcie 0000:01:00.0: mwifiex_cfg80211_change_beacon: setting mgmt ies failed

@erdoukki
Copy link
Author

erdoukki commented Aug 8, 2021

Slow and very unstable !

@erdoukki
Copy link
Author

https://forum.openwrt.org/t/mwifiex-bugs-on-espressobin-ultra/103087

@erdoukki erdoukki changed the title MWIFIEX - MVEBU - EspressoBin ULTRA wifi - BUGS with OpenWrt 21.02-RC mwifiex 1.0 (16.68.10.p159) - PCIEUSB-8997 firmware is buggy Aug 10, 2021
@erdoukki
Copy link
Author

Slow and very unstable !

[ 434.515599] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p195)

Crash at network restart !

Only reboot get the WiFi working, since network restart, and reboot required again !

@erdoukki
Copy link
Author

I give a try to : MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145)
from https://github.com/NXP/mwifiex-firmware/blob/5446916b53de395245d89400dea566055ec4502c/mrvl/pcieusb8997_combo_v4.bin

[    9.846954] mwifiex_pcie 0000:01:00.0: info: FW download over, size 631012 bytes
[   10.692912] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   10.755992] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145) 
[   10.764556] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p145)

@erdoukki
Copy link
Author

I give a try to : MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145)

Network could now be restarted...
Better results with this version for now !
Will test longer...

@erdoukki
Copy link
Author

I give a try to : MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145)

Still buggy :

[ 3048.066459] ------------[ cut here ]------------
[ 3048.071327] NETDEV WATCHDOG: wlan0 (mwifiex_pcie): transmit queue 1 timed out
[ 3048.079046] WARNING: CPU: 0 PID: 0 at 0xffffffc010639750
[ 3048.084559] Modules linked in: xt_connlimit pppoe ppp_async option nf_conncount iptable_nat cdc_mbim xt_state xt_nat xt_helper xt_conntrack xt_connmark xt_connbytes xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT usb_wwan qmi_wwan pppox ppp_generic nf_nat nf_flow_table_hw nf_flow_table nf_conntrack mwifiex_pcie mwifiex ipt_REJECT cfg80211 cdc_ncm xt_time xt_tcpudp xt_tcpmss xt_statistic xt_recent xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY usbserial usbnet slhc rtc_pcf8563 nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt compat cdc_wdm i2c_pxa xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set
[ 3048.085365]  nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 zram zsmalloc mii gpio_button_hotplug
[ 3048.191007] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.4.137 #0
[ 3048.197237] Hardware name: Globalscale Marvell ESPRESSOBin Ultra Board (DT)
[ 3048.204468] pstate: 60400005 (nZCv daif +PAN -UAO)
[ 3048.209446] pc : 0xffffffc010639750
[ 3048.213078] lr : 0xffffffc010639750
[ 3048.216705] sp : ffffffc010003dc0
[ 3048.220155] x29: ffffffc010003dc0 x28: ffffffc0109350c0 
[ 3048.225685] x27: 0000000000000140 x26: 00000000ffffffff 
[ 3048.231214] x25: 0000000000000000 x24: 0000000000000000 
[ 3048.236742] x23: 0000000000000001 x22: ffffff803c89c800 
[ 3048.242270] x21: ffffff803c89cc80 x20: ffffffc010936000 
[ 3048.247798] x19: 0000000000000001 x18: 0000000000000000 
[ 3048.253325] x17: 0000000000000000 x16: 0000000000000000 
[ 3048.258851] x15: 0000000000000000 x14: ffffffc0109a2a12 
[ 3048.264378] x13: 0000000000000000 x12: ffffffc0109a2000 
[ 3048.269908] x11: ffffffc010946000 x10: 0000000000000010 
[ 3048.275434] x9 : 0000000000000000 x8 : 756575712074696d 
[ 3048.280961] x7 : 736e617274203a29 x6 : 0000000000000001 
[ 3048.286487] x5 : 0000000000000000 x4 : 0000000000000000 
[ 3048.292014] x3 : 0000000000000000 x2 : ffffff803fdcebd0 
[ 3048.297539] x1 : ffffff803fdcc578 x0 : 0000000000000041 
[ 3048.303066] Call trace:
[ 3048.305630]  0xffffffc010639750
[ 3048.308904]  0xffffffc01010cb08
[ 3048.312178]  0xffffffc01010cdf8
[ 3048.315451]  0xffffffc0100812d4
[ 3048.318724]  0xffffffc0100a5404
[ 3048.321996]  0xffffffc0100f2634
[ 3048.325268]  0xffffffc0100810ac
[ 3048.328540]  0xffffffc010082df0
[ 3048.331813]  0xffffffc0100864f0
[ 3048.335085]  0xffffffc0100d1ffc
[ 3048.338357]  0xffffffc0100d2180
[ 3048.341628]  0xffffffc01077eec8
[ 3048.344900]  0xffffffc0108c086c
[ 3048.348174]  0xffffffc0108c0d28
[ 3048.351449] ---[ end trace 1168348e711ed524 ]---
[ 3048.356613] mwifiex_pcie 0000:01:00.0: 4295242133 : Tx timeout(#1), bss_type-num = 1-0
[ 3054.546288] mwifiex_pcie 0000:01:00.0: 4295242752 : Tx timeout(#2), bss_type-num = 1-0
[ 3060.306044] mwifiex_pcie 0000:01:00.0: 4295243328 : Tx timeout(#3), bss_type-num = 1-0
[ 3066.065733] mwifiex_pcie 0000:01:00.0: 4295243904 : Tx timeout(#4), bss_type-num = 1-0
[ 3381.097672] mwifiex_pcie 0000:01:00.0: 4295275408 : Tx timeout(#1), bss_type-num = 1-0
[ 3391.097460] mwifiex_pcie 0000:01:00.0: 4295276408 : Tx timeout(#2), bss_type-num = 1-0
[ 3401.097404] mwifiex_pcie 0000:01:00.0: 4295277408 : Tx timeout(#3), bss_type-num = 1-0
[ 3411.097611] mwifiex_pcie 0000:01:00.0: 4295278408 : Tx timeout(#4), bss_type-num = 1-0
[ 3421.097061] mwifiex_pcie 0000:01:00.0: 4295279408 : Tx timeout(#5), bss_type-num = 1-0
[ 3616.054327] mwifiex_pcie 0000:01:00.0: 4295298904 : Tx timeout(#1), bss_type-num = 1-0
[ 3621.094253] mwifiex_pcie 0000:01:00.0: 4295299408 : Tx timeout(#2), bss_type-num = 1-0
[ 3631.094131] mwifiex_pcie 0000:01:00.0: 4295300408 : Tx timeout(#3), bss_type-num = 1-0
[ 3641.094082] mwifiex_pcie 0000:01:00.0: 4295301408 : Tx timeout(#4), bss_type-num = 1-0
[ 3651.094035] mwifiex_pcie 0000:01:00.0: 4295302408 : Tx timeout(#5), bss_type-num = 1-0
[ 3661.093977] mwifiex_pcie 0000:01:00.0: 4295303408 : Tx timeout(#6), bss_type-num = 1-0
[ 3821.093104] mwifiex_pcie 0000:01:00.0: 4295319408 : Tx timeout(#1), bss_type-num = 1-0
[ 3831.093062] mwifiex_pcie 0000:01:00.0: 4295320408 : Tx timeout(#2), bss_type-num = 1-0
[ 3841.092999] mwifiex_pcie 0000:01:00.0: 4295321408 : Tx timeout(#3), bss_type-num = 1-0
[ 3851.092853] mwifiex_pcie 0000:01:00.0: 4295322408 : Tx timeout(#4), bss_type-num = 1-0
[ 3861.092955] mwifiex_pcie 0000:01:00.0: 4295323408 : Tx timeout(#5), bss_type-num = 1-0
[ 3871.092876] mwifiex_pcie 0000:01:00.0: 4295324408 : Tx timeout(#6), bss_type-num = 1-0
[ 3881.092845] mwifiex_pcie 0000:01:00.0: 4295325408 : Tx timeout(#7), bss_type-num = 1-0
[ 3881.101189] mwifiex_pcie 0000:01:00.0: tx_timeout_cnt exceeds threshold.	Triggering card reset!
[ 3881.123091] mwifiex: Have pending ack frames!
[ 3881.127618] mwifiex: Have pending ack frames!
[ 3881.132133] mwifiex: Have pending ack frames!
[ 3881.136674] mwifiex: Have pending ack frames!
[ 3881.141186] mwifiex: Have pending ack frames!
[ 3881.145712] mwifiex: Have pending ack frames!
[ 3881.150212] mwifiex: Have pending ack frames!
[ 3881.154734] mwifiex: Have pending ack frames!
[ 3881.159234] mwifiex: Have pending ack frames!
[ 3881.163741] mwifiex: Have pending ack frames!
[ 3881.168244] mwifiex: Have pending ack frames!
[ 3881.172747] mwifiex: Have pending ack frames!
[ 3881.177245] mwifiex: Have pending ack frames!
[ 3881.181883] mwifiex: Have pending ack frames!
[ 3881.186457] mwifiex: Have pending ack frames!
[ 3881.198336] mwifiex_pcie 0000:01:00.0: info: shutdown mwifiex...
[ 3881.204602] mwifiex: Have pending ack frames!
[ 3881.209098] mwifiex: Have pending ack frames!
[ 3881.213624] mwifiex: Have pending ack frames!
[ 3881.218117] mwifiex: Have pending ack frames!
[ 3881.222609] mwifiex: Have pending ack frames!
[ 3881.227558] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[ 3881.233782] mwifiex_pcie 0000:01:00.0: Failed to delete mgmt IEs!
[ 3881.240068] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[ 3881.246276] mwifiex_pcie 0000:01:00.0: Failed to stop the BSS
[ 3881.253680] br-lan: port 5(wlan0) entered disabled state
[ 3881.265873] device wlan0 left promiscuous mode
[ 3881.270484] br-lan: port 5(wlan0) entered disabled state
[ 3881.314089] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[ 3881.320447] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[ 3881.673173] mwifiex_pcie 0000:01:00.0: info: dnld wifi firmware from 174940 bytes
[ 3883.063810] mwifiex_pcie 0000:01:00.0: info: FW download over, size 631012 bytes
[ 3883.782802] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[ 3883.842146] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145) 
[ 3883.850682] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p145) 
[ 4077.794696] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[ 4077.823906] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1
[ 4078.073527] br-lan: port 5(wlan1) entered blocking state
[ 4078.079042] br-lan: port 5(wlan1) entered disabled state
[ 4078.084936] device wlan1 entered promiscuous mode

@erdoukki
Copy link
Author

16.68.1.p140

root@ULTRA-5G:~# dmesg | grep wifi

[    8.923516] mwifiex_pcie: PCI memory map Virt0: 0000000096d3b7c6 PCI memory map Virt2: 000000000fcae741
[   10.091709] mwifiex_pcie 0000:01:00.0: info: FW download over, size 622532 bytes
[   10.933277] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   10.996724] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p140) 
[   11.005299] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p140) 
[   18.975739] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   19.005051] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1
[   44.923101] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1

two clients : OK
looks to work fine !

@erdoukki
Copy link
Author

16.68.1.p133

root@ULTRA-5G:~# dmesg | grep wifi

[    8.986976] mwifiex_pcie: PCI memory map Virt0: 000000004831567e PCI memory map Virt2: 0000000027b0c31e
[   10.154634] mwifiex_pcie 0000:01:00.0: info: FW download over, size 620800 bytes
[   10.993007] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   11.044965] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p133) 
[   11.053476] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p133) 
[   18.708355] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   18.741340] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1
[   44.358715] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1

two clients : OK
looks to work fine !

@erdoukki
Copy link
Author

16.68.1.p97

root@ULTRA-5G:~# dmesg | grep wifi

[    8.807778] mwifiex_pcie: PCI memory map Virt0: 00000000cd449e21 PCI memory map Virt2: 0000000097a3ae41
[    9.974986] mwifiex_pcie 0000:01:00.0: info: FW download over, size 597136 bytes
[   10.702868] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[   10.764722] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p97) 
[   10.773164] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p97) 
[   18.761495] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1
[   18.798401] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xd1 error, result=0x1
[   44.430588] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x20 error, result=0x1

two clients : OK
looks to work fine !

@erdoukki
Copy link
Author

16.68.1.p70

KO
Not loading firmware

root@ULTRA-5G:~# dmesg | grep wifi

[    8.823912] mwifiex_pcie: PCI memory map Virt0: 0000000065b7d8bd PCI memory map Virt2: 00000000fcc32dbc
[    9.016220] mwifiex_pcie 0000:01:00.0: mwifiex_prog_fw_w_helper: Card failed to ACK download
[    9.025042] mwifiex_pcie 0000:01:00.0: prog_fw failed ret=0xffffffff
[    9.031610] mwifiex_pcie 0000:01:00.0: info: _mwifiex_fw_dpc: unregister device
[    9.040320] mwifiex_pcie 0000:01:00.0: performing cancel_work_sync()...
[    9.047282] mwifiex_pcie 0000:01:00.0: cancel_work_sync() done

@erdoukki
Copy link
Author

  • W16.68.10.p159 = KO
  • W16.68.1.p195 = KO
  • V16.68.1.p145 = OK
  • 16.68.1.p140 = OK
  • 16.68.1.p133 = OK
  • 16.68.1.p97 = OK
  • 16.68.1.p70 = KO

Tests (quick tests) made only with ONE AP and TWO CLIENTS on the AP...

Config used :
cat /etc/config/wireless

config wifi-device 'radio0'
	option type 'mac80211'
	option path 'soc/d0070000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0'
	option htmode 'HT20'
	option hwmode '11g'
	option channel 'auto'
	option log_level '1'
	option cell_density '0'
	option country 'FR'
	option legacy_rates '1'

config wifi-iface 'default_radio0'
	option device 'radio0'
	option network 'lan'
	option mode 'ap'
	option ssid 'ACCESSPOINT'
	option key 'PASSWORD'
	option encryption 'psk2'
	option skip_inactivity_poll '1'

@erdoukki
Copy link
Author

@pali hope I forget nothing ! ;-)

@pali
Copy link

pali commented Sep 25, 2021

[ 9.016220] mwifiex_pcie 0000:01:00.0: mwifiex_prog_fw_w_helper: Card failed to ACK download

Error message Card failed to ACK download is here:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/net/wireless/marvell/mwifiex/pcie.c?h=v5.14#n2386

And is caused by loop retries, up the MAX_POLL_TRIES = 100 tries.

MAX_POLL_TRIES is defined here:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/net/wireless/marvell/mwifiex/fw.h?h=v5.14#n126

You could try to increase MAX_POLL_TRIES if it helps (maybe firmware is slower). E.g. to very big value 1000000.

@erdoukki
Copy link
Author

Thanks for the information @pali ...
I think this old 16.68.1.p70 firmware from 2016-09-12 may be forget !

@erdoukki
Copy link
Author

V16.68.1.p145

I will test more with the V16.68.1.p145 !
latest which allow more than 1 clients...

@pali
Copy link

pali commented Sep 25, 2021

Well, driver should work with any firmware version. Above MAX_POLL_TRIES is used for lot of other actions. And if that retry count is small it could mean that also other commands could timeout / cause issues. So if changing retry count for older firmware version helps it could mean that driver needs more tweaks also for new firmware versions.

@erdoukki
Copy link
Author

I get issue in old tests with V16.68.1.p145 : #1 (comment)
Hope the BSOD where from other components !

@erdoukki
Copy link
Author

erdoukki commented Sep 25, 2021 •
edited
Loading

Well, driver should work with any firmware version. Above MAX_POLL_TRIES is used for lot of other actions. And if that retry count is small it could mean that also other commands could timeout / cause issues. So if changing retry count for older firmware version helps it could mean that driver needs more tweaks also for new firmware versions.

Okay, but I have not compile the OpenWrt firmware I actually use on my ULTRA.
I use only an official one 21.02.x !
If you want tests with the recommended value, I can do, but later.
I have first to make a custom firmware.

@pali
Copy link

pali commented Sep 25, 2021

You can also put this card into any other device (for which you can re-compile kernel easily).

@pali
Copy link

pali commented Sep 25, 2021

  • W16.68.10.p159 = KO
  • W16.68.1.p195 = KO
  • V16.68.1.p145 = OK
  • 16.68.1.p140 = OK
  • 16.68.1.p133 = OK
  • 16.68.1.p97 = OK
  • 16.68.1.p70 = KO

Perfect! So obviously problematic is version W16.68.1.p195.

Version W16.68.1.p195 of pcieusb8997_combo_v4.bin was included into linux-firmware repository by this pull request:
https://lore.kernel.org/all/CA+5PVA5yQbjg3vaT7F8120B6ngLn7+sZC0OWt0KoUiQR9hS4FA@mail.gmail.com/

And latest version W16.68.10.p159 of pcieusb8997_combo_v4.bin by this pull request:
https://lore.kernel.org/linux-firmware/CA+5PVA5on7+CRtEV7tThPxgucwt3W9i-tEXm4cgH-AmMB-Jrtg@mail.gmail.com/

Please send this test summary to [email protected] mailing list and to Josh Boyer (merged above pull requests to linux-firmware repository) and explain this issue. It is obviously critical usability error. Also add into copy all people from above two pull request emails, so they would be notified about this issue. Also add [email protected] to copy so other developers would see this issue (you can browse archive to see that mwifiex is under active discussion). And add also me to the copy :)

Either responsible people will come up with patches (to firmware or to driver) OR firmware files in linux-fimware would be revered.

@erdoukki
Copy link
Author

erdoukki commented Sep 25, 2021 •
edited
Loading

You can also put this card into any other device (for which you can re-compile kernel easily).

No !
It is a soldered component of the EspressoBin-Ultra.
But I have some PCI with this chipset...
I also have another EspressoBin-Ultra.
I will prepare one !

Another question :
Do you know if the actual linux-mwifiex is using NXP mwifiex driver ?
I received from NXP support this mwifiex details, but they said to not plan to upstream it : Wifi driver | CodeAurora: mwifiex​ https://source.codeaurora.org/external/nxpwifi/mwifiex | Lastest offical release is 8649a841364622db5cc36c71563f96f070b44142 (master)

Perfect! So obviously problematic is version W16.68.1.p195.

Okay, I will send the test summary

@pali
Copy link

pali commented Sep 25, 2021

Do you know if the actual linux-mwifiex is using NXP mwifiex driver ?

It is using mwifiex driver which Marvell developers (now they are in NXP as NXP bought wireless division from Marvell including developers) developed, send to upstream and maintained it. So ex-Marvell/NXP already upstreamed it in commit, also see history 1 2.

I received from NXP support this mwifiex details, but they said to not plan to upstream it : Wifi driver | CodeAurora: mwifiex​ https://source.codeaurora.org/external/nxpwifi/mwifiex | Lastest offical release is 8649a841364622db5cc36c71563f96f070b44142 (master)

I did not know about it, but it seems like fork of older linux mwifiex driver which NXP modified? No idea.

@pali
Copy link

pali commented Sep 25, 2021

Well, driver should work with any firmware version. Above MAX_POLL_TRIES is used for lot of other actions. And if that retry count is small it could mean that also other commands could timeout / cause issues. So if changing retry count for older firmware version helps it could mean that driver needs more tweaks also for new firmware versions.

In that mwifiex_8997 is similar code with MAX_POLL_TRIES = 100 but at the end of loop is udelay(100):
https://source.codeaurora.org/external/nxpwifi/mwifiex/tree/mwifiex_8997/mlinux/moal_pcie.c?h=caf/master&id=070397228c46e0a6afce4f627b032d3818cc1356#n1202
In upstream linux version is at the end of loop usleep_range(10, 20); which means that NXP version waits 10x more than upstream linux version.

@erdoukki
Copy link
Author

erdoukki commented Sep 26, 2021 •
edited
Loading

16.68.1.p70 : Still KO

With this patch:

mvebu: mwifiex: fix max poll tries

mwifiex 1.0 (16.68.10.p159) - PCIEUSB-8997 firmware is buggy
https://github.com/NXP/mwifiex-firmware/issues/1

    Well, driver should work with any firmware version.
    Above MAX_POLL_TRIES is used for lot of other actions.
    And if that retry count is small it could mean that also other commands
    could timeout / cause issues.
    So if changing retry count for older firmware version helps it could mean
    that driver needs more tweaks also for new firmware versions.

https://github.com/NXP/mwifiex-firmware/issues/1#issuecomment-927150401

Cc: [email protected]
Signed-off-by: Kerma Gérald <[email protected]>

--- a/drivers/net/wireless/marvell/mwifiex/fw.h
+++ b/drivers/net/wireless/marvell/mwifiex/fw.h
@@ -123,7 +123,7 @@ enum KEY_TYPE_ID {
 
 #define WAPI_KEY_LEN			(WLAN_KEY_LEN_SMS4 + PN_LEN + 2)
 
-#define MAX_POLL_TRIES			100
+#define MAX_POLL_TRIES			1000000
 #define MAX_FIRMWARE_POLL_TRIES			150
 
 #define FIRMWARE_READY_SDIO				0xfedc

root@OpenWrt:/# dmesg | grep wifi                                                                                                                      
[    7.868764] mwifiex_pcie: PCI memory map Virt0: 000000000e906f19 PCI memory map Virt2: 0000000088ad57ae                                             
[    8.007776] mwifiex_pcie 0000:01:00.0: mwifiex_prog_fw_w_helper: Card failed to ACK download                                                        
[    8.016523] mwifiex_pcie 0000:01:00.0: prog_fw failed ret=0xffffffff                                                                                
[    8.023075] mwifiex_pcie 0000:01:00.0: info: _mwifiex_fw_dpc: unregister device                                                                     
[    8.030980] mwifiex_pcie 0000:01:00.0: performing cancel_work_sync()...                                                                             
[    8.037814] mwifiex_pcie 0000:01:00.0: cancel_work_sync() done

@erdoukki
Copy link
Author

#define MAX_FIRMWARE_POLL_TRIES 150

May be this specific loading problem may need to modify also MAX_FIRMWARE_POLL_TRIES ?

@erdoukki
Copy link
Author

erdoukki commented Sep 26, 2021 •
edited
Loading 

OpenWrt SNAPSHOT, r17625+1-fc050c7b53

I got kernel panic at boot ! and reboot with a loop of kernel panic !

I think theses OOPS are not related of the MWIFIEX patch, but may be this board is bugging related to MarvellEmbeddedProcessors/linux-marvell#20 !

I have 4 EspressoBin-Ultras, two are working partially fine, but are still in OpenWrt 21.02.0-RC, one another, my third one, crash too easily and fastly, and the last fourth one is still in stock for now.
The one used for yesterday MWIFIEX tests is a working ULTRA that I do not want to flash with a custom firmware...

root@(none):/# [   12.124603] ------------[ cut here ]------------                                                                                     
[   12.129399] Kernel BUG at do_exit+0x5bc/0x8f0 [verbose debug info unavailable]                                                                      
[   12.136853] Internal error: Oops - BUG: 0 [#1] SMP                                                                                                  
[   12.141791] Modules linked in: pppoe ppp_async iptable_nat xt_state xt_nat xt_conntrack xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT pppox ppp_geg
[   12.231251] CPU: 1 PID: 1601 Comm: basename Not tainted 5.10.64 #0                                                                                  
[   12.237626] Hardware name: Globalscale Marvell ESPRESSOBin Ultra Board (DT)                                                                         
[   12.244805] pstate: 00400005 (nzcv daif +PAN -UAO -TCO BTYPE=--)                                                                                    
[   12.251004] pc : do_exit+0x5bc/0x8f0                                                                                                                
[   12.254686] lr : do_exit+0x190/0x8f0                                                                                                                
[   12.258367] sp : ffffffc011aabdc0                                                                                                                   
[   12.261780] x29: ffffffc011aabdc0 x28: ffffff8000fc9700                                                                                             
[   12.267259] x27: 0000000000000000 x26: 0000000000000000                                                                                             
[   12.272735] x25: 0000000000000000 x24: 0000000000000000                                                                                             
[   12.278212] x23: ffffff8000d926e8 x22: 0000007f9057a6b0                                                                                             
[   12.283688] x21: ffffff8000fc9700 x20: ffffff8000fc9700                                                                                             
[   12.289165] x19: ffffff8000d92680 x18: 0000000000000000                                                                                             
[   12.294641] x17: 0000000000000000 x16: 0000000000000000                                                                                             
[   12.300117] x15: 0000000000000000 x14: 0000000000000000                                                                                             
[   12.305594] x13: 0000000000000000 x12: 0000000000000000                                                                                             
[   12.311070] x11: 0000000000000000 x10: 0000000000000000                                                                                             
[   12.316547] x9 : 0000000000000000 x8 : 0000000000000000                                                                                             
[   12.322023] x7 : 0000000000000000 x6 : 0000000000000000                                                                                             
[   12.327500] x5 : 000000000066751a x4 : ffffff8000fc9700                                                                                             
[   12.332976] x3 : 0000000000000000 x2 : ffffff8000d926d0                                                                                             
[   12.338453] x1 : 0000000000000000 x0 : 6163735f3939636f                                                                                             
[   12.343930] Call trace:                                                                                                                             
[   12.346449]  do_exit+0x5bc/0x8f0                                                                                                                    
[   12.349773]  do_group_exit+0x38/0xa0                                                                                                                
[   12.353455]  __arm64_sys_exit_group+0x18/0x20                                                                                                       
[   12.357948]  do_el0_svc+0xbc/0x140                                                                                                                  
[   12.361454]  el0_svc+0x14/0x20                                                                                                                      
[   12.364599]  el0_sync_handler+0xa4/0x140                                                                                                            
[   12.368641]  el0_sync+0x164/0x180                                                                                                                   
[   12.372061] Code: b8236801 9401a36c 94018003 9400ae9e (d4210000)                                                                                    
[   12.378342] ---[ end trace a991848b7964b43e ]---                                                                                                    
[   12.383101] Kernel panic - not syncing: Oops - BUG: Fatal exception                                                                                 
[   12.389562] SMP: stopping secondary CPUs                                                                                                            
[   12.393606] Kernel Offset: disabled                                                                                                                 
[   12.397199] CPU features: 0x0000002,00002008                                                                                                        
[   12.401597] Memory Limit: none                                                                                                                      
[   12.404743] Rebooting in 3 seconds..

@erdoukki
Copy link
Author

erdoukki commented Sep 26, 2021 •
edited
Loading

W16.68.10.p159 = KO (1 client only)

With this patch: #1 (comment)

root@OpenWrt:/# dmesg | grep wifi
[    7.859923] mwifiex_pcie: PCI memory map Virt0: 00000000da6221ef PCI memory map Virt2: 000000002eeadab5
[    8.917241] mwifiex_pcie 0000:01:00.0: info: FW download over, size 638992 bytes
[    9.755119] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[    9.826718] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.10.p159) 
[    9.835325] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.10.p159)

Loop issue

[   74.296964] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0xb1 error, result=0x1                                                                
[   74.304168] mwifiex_pcie 0000:01:00.0: Failed to start the BSS                                                                             
[   74.310211] mwifiex_pcie 0000:01:00.0: Failed to start AP

resolved (known issue) by adding to /etc/config/wireless :

	option legacy_rates '1'

new error, and no access to AP from clients !?

netlink: 'iw': attribute type 302 has an invalid length.

UPDATE :
Done a reboot...
Then 1 client access to AP (with success) :

Sun Sep 26 11:35:37 2021 daemon.info hostapd: wlan0: STA 76:56:4c:46:24:17 IEEE 802.11: associated                                                       
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: event 1 notification                                                    
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: start authentication                                                    
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 IEEE 802.1X: unauthorizing port                                              
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: sending 1/4 msg of 4-Way Handshake                                      
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: received EAPOL-Key frame (2/4 Pairwise)                                 
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: sending 3/4 msg of 4-Way Handshake                                      
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: received EAPOL-Key frame (4/4 Pairwise)                                 
Sun Sep 26 11:35:37 2021 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 76:56:4c:46:24:17                                                                
Sun Sep 26 11:35:37 2021 daemon.debug hostapd: wlan0: STA 76:56:4c:46:24:17 IEEE 802.1X: authorizing port                                                
Sun Sep 26 11:35:37 2021 daemon.info hostapd: wlan0: STA 76:56:4c:46:24:17 RADIUS: starting accounting session B9933FE5E055B3A8                          
Sun Sep 26 11:35:37 2021 daemon.info hostapd: wlan0: STA 76:56:4c:46:24:17 WPA: pairwise key handshake completed (RSN)                                   
Sun Sep 26 11:35:37 2021 daemon.notice hostapd: wlan0: EAPOL-4WAY-HS-COMPLETED 76:56:4c:46:24:17

Second client (try to) access (unsuccessful) :

Sun Sep 26 11:36:41 2021 daemon.info hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.11: associated                                                       
Sun Sep 26 11:36:41 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: event 1 notification                                                    
Sun Sep 26 11:36:41 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: start authenti[  350.996023] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 01
cation                                                                                                                                                   
Sun Sep 26 11:36:41 2021 [  351.006151] mwifiex_pcie 0000:01:00.0: crypto keys added                                                                     
daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.1X: unauthorizing port                                                                       
Sun Sep 26 11:36:41 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: sending 1/4 msg of 4-Way Handshake                                      
Sun Sep 26 11:36:41 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: received EAPOL-Key frame (2/4 Pairwise)                                 
Sun Sep 26 11:36:41 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: sending 3/4 msg of 4-Way Handshake                                      
Sun Sep 26 11:36:41 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: received EAPOL-Key frame (4/4 Pairwise)                                 
Sun Sep 26 11:36:41 2021 kern.info kernel: [  350.996023] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1                                
Sun Sep 26 11:36:41 2021 kern.info kernel: [  351.006151] mwifiex_pcie 0000:01:00.0: crypto keys added                                                   
Sun Sep 26 11:36:41 2021 daemon.err hostapd: nl80211: kernel reports: key addition failed                                                                
Sun Sep 26 11:36:42 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: event 3 notification                                                    
Sun Sep 26 11:36:42 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.1X: unauthorizing port                                              
Sun Sep 26 11:36:42 2021 daemon.info hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.11: disassociated                                                    
Sun Sep 26 11:36:42 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: event 2 notification                                                    
Sun Sep 26 11:36:42 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.1X: unauthorizing port                                              
Sun Sep 26 11:36:45 2021 daemon.info hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.11: associated                                                       
Sun Sep 26 11:36:45 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: event 1 notification                                                    
Sun Sep 26 11:36:45 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: start authe[  354.873937] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e1
ntication                                                                                                                                                
Sun Sep 26 11:36:45 20[  354.884056] mwifiex_pcie 0000:01:00.0: crypto keys added

This error loop !!!

Result :
Still only 1 client only !

@erdoukki
Copy link
Author

erdoukki commented Sep 26, 2021 •
edited
Loading

W16.68.10.p159 = KO (1 client only)

If I de-authenticate the first client, the second get access successfully !

Sun Sep 26 11:44:59 2021 daemon.info hostapd: wlan0: STA 76:56:4c:46:24:17 IEEE 802.11: disassociated                                                                                               
Sun Sep 26 11:45:02 2021 daemon.info hostapd: wlan0: STA 76:56:4c:46:24:17 IEEE 802.11: disassociated                                                                                               
Sun Sep 26 11:45:08 2021 daemon.info hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.11: associated                                                                                                  
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: event 1 notification                                                                                               
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: start authentication                                                                                               
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.1X: unauthorizing port                                                                                         
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: sending 1/4 msg of 4-Way Handshake                                                                                 
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: received EAPOL-Key frame (2/4 Pairwise)                                                                            
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: sending 3/4 msg of 4-Way Handshake                                                                                 
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: received EAPOL-Key frame (4/4 Pairwise)                                                                            
Sun Sep 26 11:45:08 2021 daemon.notice hostapd: wlan0: AP-STA-CONNECTED d0:ab:d5:51:82:18                                                                                                           
Sun Sep 26 11:45:08 2021 daemon.debug hostapd: wlan0: STA d0:ab:d5:51:82:18 IEEE 802.1X: authorizing port                                                                                           
Sun Sep 26 11:45:08 2021 daemon.info hostapd: wlan0: STA d0:ab:d5:51:82:18 RADIUS: starting accounting session 30AB20B7BFE3D796                                                                     
Sun Sep 26 11:45:08 2021 daemon.info hostapd: wlan0: STA d0:ab:d5:51:82:18 WPA: pairwise key handshake completed (RSN)                                                                              
Sun Sep 26 11:45:08 2021 daemon.notice hostapd: wlan0: EAPOL-4WAY-HS-COMPLETED d0:ab:d5:51:82:18

I confirm that this versions still work with one client only.

The errors looks like to be from the firmware itself :

Sun Sep 26 11:45:26 2021 kern.info kernel: [  875.856563] mwifiex_pcie 0000:01:00.0: CMD_RESP: cmd 0x5e error, result=0x1                                                                           
Sun Sep 26 11:45:26 2021 kern.info kernel: [  875.866746] mwifiex_pcie 0000:01:00.0: crypto keys added

@erdoukki
Copy link
Author

V16.68.1.p145

I will test more with the V16.68.1.p145 ! latest which allow more than 1 clients...

No WiFi AP this morning...

Uptime | 3d 2h 4m 22s

Kernel.log

[262625.404655] ------------[ cut here ]------------
[262625.409615] NETDEV WATCHDOG: wlan0 (mwifiex_pcie): transmit queue 1 timed out
[262625.417412] WARNING: CPU: 0 PID: 0 at 0xffffffc010639750
[262625.423015] Modules linked in: xt_connlimit pppoe ppp_async option nf_conncount iptable_nat cdc_mbim xt_state xt_nat xt_helper xt_conntrack xt_connmark xt_connbytes xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT usb_wwan qmi_wwan pppox ppp_generic nft_redir nft_ct nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_netlink nf_conntrack mwifiex_pcie mwifiex ipt_REJECT cfg80211 cdc_ncm xt_time xt_tcpudp xt_tcpmss xt_statistic xt_recent xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY usbserial usbnet slhc rtc_pcf8563 nft_reject_ipv6 nft_reject_ipv4 nft_reject_inet nft_reject nft_quota nft_objref nft_numgen nft_log nft_limit nft_hash nft_counter nf_tables_set nf_tables nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt compat cdc_wdm cdc_acm ohci_pci uhci_hcd ohci_platform ohci_hcd i2c_pxa xt_set ip_set_list_set ip_set_hash_netportnet
[262625.423876]  ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 zram zsmalloc mii gpio_button_hotplug
[262625.551440] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.4.137 #0
[262625.557760] Hardware name: Globalscale Marvell ESPRESSOBin Ultra Board (DT)
[262625.565081] pstate: 60400005 (nZCv daif +PAN -UAO)
[262625.570146] pc : 0xffffffc010639750
[262625.573869] lr : 0xffffffc010639750
[262625.577584] sp : ffffffc010003dc0
[262625.581125] x29: ffffffc010003dc0 x28: ffffffc0109350c0 
[262625.586746] x27: 0000000000000140 x26: 00000000ffffffff 
[262625.592365] x25: 0000000000000000 x24: 0000000000000000 
[262625.597982] x23: 0000000000000001 x22: ffffff803bd4a800 
[262625.603602] x21: ffffff803bd4ac80 x20: ffffffc010936000 
[262625.609219] x19: 0000000000000001 x18: 0000000000000000 
[262625.614835] x17: 0000000000000000 x16: 0000000000000001 
[262625.620451] x15: 0000000000000000 x14: 756f2064656d6974 
[262625.626069] x13: 2031206575657571 x12: 2074696d736e6172 
[262625.631686] x11: 74203a2965696370 x10: 5f7865696669776d 
[262625.637306] x9 : 2820306e616c7720 x8 : 3a474f4448435441 
[262625.642924] x7 : 572056454454454e x6 : 0000000000000001 
[262625.648539] x5 : 0000000000000000 x4 : 0000000000000000 
[262625.654154] x3 : 0000000000000000 x2 : ffffff803fdcebd0 
[262625.659773] x1 : ffffff803fdcc578 x0 : 0000000000000041 
[262625.665390] Call trace:
[262625.668046]  0xffffffc010639750
[262625.671410]  0xffffffc01010cb08
[262625.674772]  0xffffffc01010cdf8
[262625.678135]  0xffffffc0100812d4
[262625.681497]  0xffffffc0100a5404
[262625.684860]  0xffffffc0100f2634
[262625.688223]  0xffffffc0100810ac
[262625.691584]  0xffffffc010082df0
[262625.694947]  0xffffffc0100864f0
[262625.698292]  0xffffffc0100d1ffc
[262625.701625]  0xffffffc0100d2180
[262625.704956]  0xffffffc01077eec8
[262625.708288]  0xffffffc0108c086c
[262625.711620]  0xffffffc0108c0d28
[262625.714953] ---[ end trace 7f297389262fa128 ]---
[262625.719976] mwifiex_pcie 0000:01:00.0: 4321200135 : Tx timeout(#1), bss_type-num = 1-0
[262631.404606] mwifiex_pcie 0000:01:00.0: 4321200704 : Tx timeout(#2), bss_type-num = 1-0
[262636.444595] mwifiex_pcie 0000:01:00.0: 4321201208 : Tx timeout(#3), bss_type-num = 1-0
[262646.444496] mwifiex_pcie 0000:01:00.0: 4321202208 : Tx timeout(#4), bss_type-num = 1-0
[262881.401640] mwifiex_pcie 0000:01:00.0: 4321225704 : Tx timeout(#1), bss_type-num = 1-0
[262886.441625] mwifiex_pcie 0000:01:00.0: 4321226208 : Tx timeout(#2), bss_type-num = 1-0
[262896.441487] mwifiex_pcie 0000:01:00.0: 4321227208 : Tx timeout(#3), bss_type-num = 1-0
[262906.441246] mwifiex_pcie 0000:01:00.0: 4321228208 : Tx timeout(#4), bss_type-num = 1-0
[262916.441239] mwifiex_pcie 0000:01:00.0: 4321229208 : Tx timeout(#5), bss_type-num = 1-0
[262926.441124] mwifiex_pcie 0000:01:00.0: 4321230208 : Tx timeout(#6), bss_type-num = 1-0
[262936.440981] mwifiex_pcie 0000:01:00.0: 4321231208 : Tx timeout(#7), bss_type-num = 1-0
[262936.449330] mwifiex_pcie 0000:01:00.0: tx_timeout_cnt exceeds threshold.	Triggering card reset!
[262936.471701] mwifiex: Have pending ack frames!
[262936.476325] mwifiex: Have pending ack frames!
[262936.480964] mwifiex: Have pending ack frames!
[262936.485558] mwifiex: Have pending ack frames!
[262936.490148] mwifiex: Have pending ack frames!
[262936.494777] mwifiex: Have pending ack frames!
[262936.499376] mwifiex: Have pending ack frames!
[262936.503999] mwifiex: Have pending ack frames!
[262936.508600] mwifiex: Have pending ack frames!
[262936.513203] mwifiex: Have pending ack frames!
[262936.517788] mwifiex: Have pending ack frames!
[262936.522388] mwifiex: Have pending ack frames!
[262938.308851] mwifiex_pcie 0000:01:00.0: info: shutdown mwifiex...
[262938.315980] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[262938.322351] mwifiex_pcie 0000:01:00.0: Failed to delete mgmt IEs!
[262938.328738] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[262938.335128] mwifiex_pcie 0000:01:00.0: Failed to stop the BSS
[262938.342785] br-lan: port 5(wlan0) entered disabled state
[262938.356275] device wlan0 left promiscuous mode
[262938.361025] br-lan: port 5(wlan0) entered disabled state
[262938.381539] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[262938.387859] mwifiex_pcie 0000:01:00.0: PREP_CMD: card is removed
[262938.598022] device lan0 left promiscuous mode
[262938.602826] br-lan: port 1(lan0) entered disabled state
[262938.696073] device lan1 left promiscuous mode
[262938.700970] br-lan: port 2(lan1) entered disabled state
[262938.753680] device lan2 left promiscuous mode
[262938.758561] br-lan: port 3(lan2) entered disabled state
[262938.770982] mwifiex_pcie 0000:01:00.0: info: dnld wifi firmware from 174940 bytes
[262938.849118] device lan3 left promiscuous mode
[262938.854156] br-lan: port 4(lan3) entered disabled state
[262939.063634] mv88e6085 d0032004.mdio-mii:03 lan0: configuring for phy/ link mode
[262939.084574] 8021q: adding VLAN 0 to HW filter on device lan0
[262939.093768] br-lan: port 1(lan0) entered blocking state
[262939.099270] br-lan: port 1(lan0) entered disabled state
[262939.121228] device lan0 entered promiscuous mode
[262939.154542] mv88e6085 d0032004.mdio-mii:03: p0: already a member of VLAN 1
[262939.203873] mv88e6085 d0032004.mdio-mii:03 lan1: configuring for phy/ link mode
[262939.232942] 8021q: adding VLAN 0 to HW filter on device lan1
[262939.262395] br-lan: port 2(lan1) entered blocking state
[262939.267903] br-lan: port 2(lan1) entered disabled state
[262939.285872] device lan1 entered promiscuous mode
[262939.325366] mv88e6085 d0032004.mdio-mii:03: p0: already a member of VLAN 1
[262939.348799] mv88e6085 d0032004.mdio-mii:03 lan2: configuring for phy/ link mode
[262939.383072] 8021q: adding VLAN 0 to HW filter on device lan2
[262939.389329] br-lan: port 3(lan2) entered blocking state
[262939.394865] br-lan: port 3(lan2) entered disabled state
[262939.409090] device lan2 entered promiscuous mode
[262939.438344] mv88e6085 d0032004.mdio-mii:03: p0: already a member of VLAN 1
[262939.456347] mv88e6085 d0032004.mdio-mii:03 lan3: configuring for phy/ link mode
[262939.470362] 8021q: adding VLAN 0 to HW filter on device lan3
[262939.482391] br-lan: port 4(lan3) entered blocking state
[262939.487902] br-lan: port 4(lan3) entered disabled state
[262939.501800] device lan3 entered promiscuous mode
[262939.529961] mv88e6085 d0032004.mdio-mii:03: p0: already a member of VLAN 1
[262940.300314] mwifiex_pcie 0000:01:00.0: info: FW download over, size 631012 bytes
[262941.020916] mwifiex_pcie 0000:01:00.0: WLAN FW is active
[262941.076125] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145) 
[262941.084815] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p145)

@erdoukki
Copy link
Author

erdoukki commented Oct 6, 2021 •
edited
Loading

V16.68.1.p145

I will test more with the V16.68.1.p145 ! latest which allow more than 1 clients...

No WiFi AP this morning...

Again... No AP this morning !

UpTime : 5d 22h 56m 32s

Wed Oct  6 08:01:29 2021 user.notice INFO: Restarting network interface: "@wan".
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.749642] ------------[ cut here ]------------
Wed Oct  6 08:01:55 2021 kern.info kernel: [511474.754599] NETDEV WATCHDOG: wlan0 (mwifiex_pcie): transmit queue 1 timed out
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.762389] WARNING: CPU: 0 PID: 0 at 0xffffffc010639750
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.767991] Modules linked in: xt_connlimit pppoe ppp_async option nf_conncount iptable_nat cdc_mbim xt_state xt_nat xt_helper xt_conntrack xt_connmark xt_connbytes xt_REDIRECT xt_MASQUERADE xt_FLOWOFFLOAD xt_CT usb_wwan qmi_wwan pppox ppp_generic nft_redir nft_ct nf_nat nf_flow_table_hw nf_flow_table nf_conntrack_netlink nf_conntrack mwifiex_pcie mwifiex ipt_REJECT cfg80211 cdc_ncm xt_time xt_tcpudp xt_tcpmss xt_statistic xt_recent xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_ecn xt_dscp xt_comment xt_TCPMSS xt_LOG xt_HL xt_DSCP xt_CLASSIFY usbserial usbnet slhc rtc_pcf8563 nft_reject_ipv6 nft_reject_ipv4 nft_reject_inet nft_reject nft_quota nft_objref nft_numgen nft_log nft_limit nft_hash nft_counter nf_tables_set nf_tables nf_reject_ipv4 nf_log_ipv4 nf_defrag_ipv6 nf_defrag_ipv4 iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt compat cdc_wdm cdc_acm ohci_pci uhci_hcd ohci_platform ohci_hcd i2c_pxa xt_set ip_set_list_set ip_set_hash_netportnet
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.768857]  ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 zram zsmalloc mii gpio_button_hotplug
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.896424] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W         5.4.137 #0
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.904176] Hardware name: Globalscale Marvell ESPRESSOBin Ultra Board (DT)
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.911495] pstate: 60400005 (nZCv daif +PAN -UAO)
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.916564] pc : 0xffffffc010639750
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.920285] lr : 0xffffffc010639750
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.923999] sp : ffffffc010003dc0
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.927537] x29: ffffffc010003dc0 x28: ffffffc0109350c0
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.933157] x27: 0000000000000140 x26: 00000000ffffffff
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.938776] x25: 0000000000000000 x24: 0000000000000000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.944392] x23: 0000000000000001 x22: ffffff803b910000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.950014] x21: ffffff803b910480 x20: ffffffc010936000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.955633] x19: 0000000000000001 x18: 0000000000000000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.961252] x17: 0000000000000000 x16: 0000000000000000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.966869] x15: 0000000000000000 x14: ffffffc0109a2a12
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.972487] x13: 0000000000000000 x12: ffffffc0109a2000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.978104] x11: ffffffc010946000 x10: 0000000000000010
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.983719] x9 : 0000000000000000 x8 : 656d697420312065
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.989339] x7 : 756575712074696d x6 : 0000000000000001
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511474.994954] x5 : 0000000000000000 x4 : 0000000000000000
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.000568] x3 : 0000000000000000 x2 : ffffff803fdcebd0
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.006187] x1 : ffffff803fdcc578 x0 : 0000000000000041
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.011803] Call trace:
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.014458]  0xffffffc010639750
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.017822]  0xffffffc01010cb08
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.021184]  0xffffffc01010cdf8
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.024545]  0xffffffc0100812d4
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.027909]  0xffffffc0100a5404
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.031271]  0xffffffc0100f2634
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.034633]  0xffffffc0100810ac
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.037994]  0xffffffc010082df0
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.041356]  0xffffffc0100864f0
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.044718]  0xffffffc0100d1ffc
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.048081]  0xffffffc0100d2184
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.051442]  0xffffffc01077eec8
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.054804]  0xffffffc0108c086c
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.058167]  0xffffffc0108c0d28
Wed Oct  6 08:01:55 2021 kern.warn kernel: [511475.061530] ---[ end trace b5207d7154a33b6b ]---
Wed Oct  6 08:01:55 2021 kern.info kernel: [511475.066774] mwifiex_pcie 0000:01:00.0: 4346085335 : Tx timeout(#1), bss_type-num = 1-0
Wed Oct  6 08:01:58 2021 daemon.info watchcat[8458]: Could not reach 8.8.8.8 via "@wwan" for "510883" seconds. Restarting "@wwan" after reaching "600" seconds
Wed Oct  6 08:01:58 2021 user.notice INFO: Restarting network interface: "@wwan".
Wed Oct  6 08:01:58 2021 daemon.info watchcat[8459]: Could not reach 8.8.8.8 via "@wan" for "507884" seconds. Restarting "@wan" after reaching "3600" seconds
Wed Oct  6 08:01:58 2021 user.notice INFO: Restarting network interface: "@wan".
....
Wed Oct  6 08:02:42 2021 kern.info kernel: [511522.431152] mwifiex_pcie 0000:01:00.0: WLAN FW is active
Wed Oct  6 08:02:42 2021 kern.info kernel: [511522.508138] mwifiex_pcie 0000:01:00.0: info: MWIFIEX VERSION: mwifiex 1.0 (16.68.1.p145)
Wed Oct  6 08:02:42 2021 kern.info kernel: [511522.516772] mwifiex_pcie 0000:01:00.0: driver_version = mwifiex 1.0 (16.68.1.p145)

Resolution :

AP available again without a Reboot but only with a manual WiFi "reset" (Restart Device + Disable Access Point + Enable Access Point).

@erdoukki
Copy link
Author

erdoukki commented Oct 9, 2021 •
edited
Loading

Well, driver should work with any firmware version. Above MAX_POLL_TRIES is used for lot of other actions. And if that retry count is small it could mean that also other commands could timeout / cause issues. So if changing retry count for older firmware version helps it could mean that driver needs more tweaks also for new firmware versions.

@pali
Do you see anything that I could test ?
The issue with the 2 latest firmwares is that I can only get one client access to the AP at same time !
Have you ever heard of this same issue ?

@pali
Copy link

pali commented Oct 9, 2021

Nothing more to test. This is NXP bug, so you have to report it to NXP... probably only NXP can fix it.

I have seen upper limit for number of clients which could connect to AP. For 8997 it was IIRC 5. So either NXP reduced it by new firmware version or introduced some bug which decreased it.

Really, you had to contact NXP for support. Per https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/MAINTAINERS is 8997 (MWIFIEX WIRELESS DRIVER) still supported.

@erdoukki
Copy link
Author

Look there is a new BSP and also new firmware ?

PCIE-WLAN-USB-BT-8997-U16-X86-W16.88.10.p173-16.26.10.p173-C4X16698_V4-MGPL
(REV W16.88.10.p173-16.26.10.p173-C4X16698_V4-MGPL)
PCIE-WLAN-USB-BT-8997-U16-X86-W16-C4X16698_V4-MGPL  
BSP, Drivers and Middleware
Oct 14, 2021

@erdoukki
Copy link
Author

Possible new firmware at NXP, I received a email announcement with:

Name/Description Type Modified Date
PCIE-WLAN-USB-BT-8997-U16-X86-W16.88.10.p173-16.26.10.p173-C4X16698_V4-MGPL (REV W16.88.10.p173-16.26.10.p173-C4X16698_V4-MGPL) ZIP    -    PCIE-WLAN-USB-BT-8997-U16-X86-W16-C4X16698_V4-MGPL     [English] BSP, Drivers and Middleware Oct 14, 2021
https://www.nxp.com/webapp/technicalupdates/download.sp?collateralId=1634245519972708786109

But the link is restricted.

I open a support request, and get answered of signing a NDA.
I open a NDA request to test the firmware, and the support answered me that the responsible do not allow me to get access !?

I have no access also at the 9098 BSP and firmware...
I will look to get my own developments on another manufacturer !
My case support were closed without further answer.

@erdoukki
Copy link
Author

erdoukki commented Feb 8, 2022 •
edited
Loading

Any news ?
@NXP will sucks as @marvell on the non-respect of them users ?
In the buzz days of the full-link-world I am still so disappointed…

all is said here, 6ae3652#commitcomment-66183539
🤬

@erdoukki
Copy link
Author

still urgently needed

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@erdoukki @pali