linux4wilc / driver

DEPRECATED: Updated Linux drivers for the ATWILC1000/ATWILC3000 products are located at https://github.com/linux4microchip/linux/tree/master/drivers/net/wireless/microchip/wilc1000. To simplify development, the legacy Linux4WILC was merged into the Linux4Microchip repo where driver development continues (Please refer latest ATWILC1000/ATWILC 3000 Wi-Fi Link Controller Linux User Guide) Driver code for Microchip ATWILC Wireless Devices (ATWILC1000 & ATWILC3000)
https://www.microchip.com/wwwproducts/en/ATWILC1000
32 stars 20 forks source link

Does the ATWILC3000 support beacon advertising ? #57

Open AntoineBore opened 5 years ago

AntoineBore commented 5 years ago

Hello,

I recently purchase and set up ATWILC3000 SD Card Evaluation Kit with my Raspberry Pi compute modules.

I want to use this module to scan/advertise beacon. When I start the beacon advertising with the commands below, I can't detect the beacon.

sudo hcitool -i hci0 cmd 0x08 0x0008 1E 02 01 06 1A FF 4C 00 02 15 11 11 22 22 33 33 44 44 55 55 66 66 77 77 88 88 00 08 00 01 C8 00
sudo hcitool -i hci0 cmd 0x08 0x0006 A0 00 A0 00 03 00 00 00 00 00 00 00 00 07 00
sudo hcitool -i hci0 cmd 0x08 0x000a 01

I used the same commands on a Raspberry Pi 3B which has an integrated Bluetooth module and it works.

That's why I'm wondering if the ATWILC3000 support beacon advertising.

EDIT: I also have scanning issues:

1st window:

$ sudo hcitool lescan --duplicates
LE Scan ...

2nd window:

$ sudo hcidump --raw
HCI sniffer - Bluetooth packet analyzer ver 5.43
device: hci0 snap_len: 1500 filter: 0xffffffff
< 01 0B 20 07 01 10 00 10 00 00 00
> 04 0E 04 0F 0B 20 00
< 01 0C 20 02 01 00
> 04 0E 04 0F 0C 20 00

And there is no data available from my beacon or smartphone bluetooth around.

After I stop the scan, I got this issue:

$ hcitool scan
Scanning ...
Inquiry failed: Operation not supported
$ sudo hcitool lescan
Set scan parameters failed: Connection timed out
$ dmesg
[ 7898.951811] Bluetooth: hci0: command 0x200b tx timeout

It's like I cannot communicate with the Bluetooth chip anymore. To resolve it, I have to download the FW again:

$ ls -la /dev
lrwxrwxrwx   1 root root           7 Jul 10 11:20 serial0 -> ttyAMA0
lrwxrwxrwx   1 root root           5 Jul 10 11:20 serial1 -> ttyS0
$ sudo echo BT_POWER_UP > /dev/wilc_bt
$ sudo echo BT_DOWNLOAD_FW > /dev/wilc_bt
$ hciattach ttyAMA0 any 115200 noflow

BTTXD <-> GPIO15 BTRXD <-> GPIO14

$ hciconfig
hci0:   Type: Primary  Bus: UART
        BD Address: F8:F0:05:C2:52:C9  ACL MTU: 27:30  SCO MTU: 0:0
        UP RUNNING
        RX bytes:390 acl:0 sco:0 events:29 errors:0
        TX bytes:380 acl:0 sco:0 commands:37 errors:0

Did I forget to set up something ?

AdhamAbozaeid commented 5 years ago

WILC3000 supports beaconing, but it doesn't support BT classic. I'm using hciconfig hci0 leadv to enable advertising, but still sending the raw HCI commands should also work. For scaning, hcitool scan is not permitted because WILC doesn't support BT classic, so lescan only will work. I tried the same sequence: - scan - operation not permitted - lescan, and I can see scan results being listed. If you are still having problems with that, please open a salesforce ticket

AntoineBore commented 5 years ago

Thank you for your answer. I want to use beaconing so I will continue to look for a solution.

Could it be a wiring problem with the UART pin ? I'm able to start lescan but after that, I can't even stop it with a ctrl+c. If I do so, I got the error: "Disable scan failed: Connection timed out" and I can see "Bluetooth: hci0: command 0x200c tx timeout" on the dmesg logs.

EDIT: I'm able to change the BD Address with the command of the wiki:

# hciattach ttyAMA0 any 115200 noflow
# hciconfig hci0 up
# hcitool cmd 0x3F 0x0054 66 55 44 33 22 11
# hcitool cmd 0x03 0x0003

So I don't think that it's a UART problem.

Is there a way to have more information with the DBG UART-USB Connector ? Right now I can only see some information when I download the FW or when I change the BD Address.

AntoineBore commented 5 years ago

I have made some more test and it looks like I'm not able to communicate with the Bluetooth module anymore when I start to scan and/or advertise.

When I start scanning or advertising, the return from the module is OK :

$ hcidump --raw
HCI sniffer - Bluetooth packet analyzer ver 5.43
device: hci0 snap_len: 1500 filter: 0xffffffff
> 04 0E 04 0F 0A 20 00

If I try to enable again scanning or advertising while one is already enabled, I will get this return:

$ hcidump --raw
HCI sniffer - Bluetooth packet analyzer ver 5.43
device: hci0 snap_len: 1500 filter: 0xffffffff
> 04 0E 04 0F 0A 20 0C

The module doesn't seem to scan nor advertise and when I try to disable the beacon, I got the Bluetooth: hci0: command 0x200a tx timeout. This doesn't make sense to me. I have opened a sales force tickets.

AntoineBore commented 5 years ago

After many tries, I "resolve" the problem by removing the WiFi. I disabled dhcpcd: $ sudo systemctl disable dhcpcd

And now, it works... do you have an idea of why I can't use both WiFi and Bluetooth ?

I think it's just a wiring problem that perturbs the module but I will still ask the question: is it possible to use the WiFi and the Bluetooth at the same time ?

Another issue is I cannot advertise and scan at the same time as I do with the Raspi 3B+. Is it normal ?

AdhamAbozaeid commented 5 years ago

Wiring shouldn't be a problem since HCI communication goes through UART lines, while wifi communication goes through SDIO/SPI lines. Is the wifi interface active when you do your tests, or is only the dhcpcd clinet running in the background?

WIFI/BLE coexistence is supported on WILC, but it doesn't support multiple roles (peripheral/central), so you can't scan and advertise at the same time

AntoineBore commented 5 years ago

That's why I thought... and if I'm able to download the Bluetooth firmware, does it mean that the SDIO connection is OK?

I tried with different setup :

  1. dhcpcd.service active, no wpa_supplicant, wlan0 up: I'm able to start the Bluetooth, download the FW and start scan OR advertise mode. The beacon or the scanner doesn't work. When I try to stop the mode I started, I get this log which I don't really understand:
    Jul 11 11:39:51 beamcm kernel: [ 2194.904849] Bluetooth firmware: mchp/wilc3000_ble_firmware.bin
    Jul 11 11:39:51 beamcm kernel: [ 2194.906103] Downloading BT firmware size = 58704 ...
    Jul 11 11:39:51 beamcm kernel: [ 2194.957563] Starting BT firmware
    Jul 11 11:39:52 beamcm kernel: [ 2195.071884] BT Start Succeeded
    Jul 11 11:39:52 beamcm kernel: [ 2195.083450] at_pwr_dev: close()
    Jul 11 11:39:53 beamcm kernel: [ 2196.311798] wilc_sdio mmc1:0001:1 wlan0: INFO [debug_thread]*** Debug Thread Running ***
    Jul 11 11:39:59 beamcm kernel: [ 2202.711765] wilc_sdio mmc1:0001:1 wlan0: INFO [debug_thread]*** Debug Thread Running ***
    Jul 11 11:40:06 beamcm kernel: [ 2209.111814] wilc_sdio mmc1:0001:1 wlan0: INFO [debug_thread]*** Debug Thread Running ***
    Jul 11 11:40:06 beamcm kernel: [ 2209.751954] INFO: task K_TXQ_TASK:928 blocked for more than 120 seconds.
    Jul 11 11:40:06 beamcm kernel: [ 2209.751980]       Tainted: G         C O      4.19.42-v7+ #1219
    Jul 11 11:40:06 beamcm kernel: [ 2209.751986] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
    Jul 11 11:40:06 beamcm kernel: [ 2209.751994] K_TXQ_TASK      D    0   928      2 0x00000000
    Jul 11 11:40:06 beamcm kernel: [ 2209.752050] [<8082642c>] (__schedule) from [<80826a9c>] (schedule+0x50/0xa8)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752072] [<80826a9c>] (schedule) from [<8082aa2c>] (schedule_timeout+0x200/0x428)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752092] [<8082aa2c>] (schedule_timeout) from [<808276cc>] (wait_for_common+0xd4/0x1b0)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752108] [<808276cc>] (wait_for_common) from [<808277c8>] (wait_for_completion+0x20/0x24)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752241] [<808277c8>] (wait_for_completion) from [<7f18c798>] (linux_wlan_txq_task+0xd4/0x234 [wilc_sdio])
    Jul 11 11:40:06 beamcm kernel: [ 2209.752363] [<7f18c798>] (linux_wlan_txq_task [wilc_sdio]) from [<801423ac>] (kthread+0x138/0x168)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752389] [<801423ac>] (kthread) from [<801010ac>] (ret_from_fork+0x14/0x28)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752398] Exception stack(0xb669ffb0 to 0xb669fff8)
    Jul 11 11:40:06 beamcm kernel: [ 2209.752408] ffa0:                                     00000000 00000000 00000000 00000000
    Jul 11 11:40:06 beamcm kernel: [ 2209.752422] ffc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
    Jul 11 11:40:06 beamcm kernel: [ 2209.752433] ffe0: 00000000 00000000 00000000 00000000 00000013 00000000
    Jul 11 11:40:12 beamcm kernel: [ 2215.511798] wilc_sdio mmc1:0001:1 wlan0: INFO [debug_thread]*** Debug Thread Running ***
    Jul 11 11:40:18 beamcm kernel: [ 2221.911807] wilc_sdio mmc1:0001:1 wlan0: INFO [debug_thread]*** Debug Thread Running ***
    Jul 11 11:40:23 beamcm kernel: [ 2225.991856] Bluetooth: hci0: command 0x200a tx timeout

In order to get this log, I executed the following commands:

sudo chmod 777 /dev/wilc_bt
sudo echo BT_POWER_UP > /dev/wilc_bt
sudo echo BT_DOWNLOAD_FW > /dev/wilc_bt
sudo hciattach ttyAMA0 any 115200 noflow
sudo hciconfig hci0 up
#Init beacon uuid, major, minor...
sudo hcitool -i hci0 cmd 0x08 0x0008 1e 02 01 06 1a ff 4c 00 02 15 11 11 22 22 33 33 44 44 55 55 66 66 77 77 88 88 00 17 f3 85 c8 00
#start advertising
sudo hcitool -i hci0 cmd 0x08 0x000a 01
#stop advertising
sudo hcitool -i hci0 cmd 0x08 0x000a 00

It's after this last command that I got "INFO: task K_TXQ_TASK:928 blocked for more than 120 seconds." and lines after it.

  1. dhcpcd.service active, no wpa_supplicant, wlan0 down, p2p0 down: Same result
  2. dhcpcd.service disable: The Bluetooth module works fine.

All those tries have been made both with the firmware of the dev and master branch.

But this is problematic for me as I need to use the WiFi and the Bluetooth at the same time. I don't understand why it doesn't work with me. Could it be a compatibility problem with the Raspberry Pi Compute Module ?

AdhamAbozaeid commented 5 years ago

Yes, that means the SDIO connection is ok since the BLE FW starts normally.

The warning looks benign to me. The TX thread is the thread that handles TX packets, and since there's no TX packets going, it's blocked waiting for events to handle. However, the thread doesn't start unless mac_open is called for one of the interfaces, so I'm not sure how that happens while you have both interfaces down in option 2. It might be that your system is still up-ing one of the interfaces. You can disable the warning using echo 0 > /proc/sys/kernel/hung_task_timeout_secs

I can't explain though how the dhcpcd.service can be affecting the BLE communication. How different are the raw hci logs in both cases where dhcpcd.service is enabled/disabled?

AntoineBore commented 5 years ago

And the "Bluetooth: hci0: command 0x200a tx timeout" ? Why would there be a timeout if there is no flow control ? Does the Bluetooth module block the line ?

I shutdown both interfaces after their initialization so the mac_open must be called before.

When dhcpcd.service is disabled, I can see all the nearby Bluetooth devices. When it is enabled, I can see the command that I executed but I'm not able to see RX commands.

The reason for me to try to remove the dhcpcd.service is that I have a lot of error/crash when I try to use the WiFi. I think that it's due to a bad SDIO connection, can you confirm? Here is the log when it fails:

Jul 11 17:28:42 beamcm kernel: [  151.640680] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.640749] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.655312] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.655385] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.656591] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.656656] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.657851] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:42 beamcm kernel: [  151.657918] wilc_sdio mmc1:0001:1: clocks still OFF. Retrying
Jul 11 17:28:44 beamcm kernel: [  153.431765] wilc_sdio mmc1:0001:1 p2p0: INFO [debug_thread]*** Debug Thread Running ***
Jul 11 17:28:45 beamcm kernel: [  154.711809] wilc_sdio mmc1:0001:1 wlan0: ERR [cfg_set:1808] Timed Out
Jul 11 17:28:45 beamcm kernel: [  154.711824] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_send_config_pkt:1903] Set Timed out
Jul 11 17:28:45 beamcm kernel: [  154.711839] wilc_sdio mmc1:0001:1 wlan0: ERR [handle_register_frame:2689] Failed to frame register
Jul 11 17:28:46 beamcm kernel: [  155.991737] wilc_sdio mmc1:0001:1 p2p0: INFO [remove_network_from_shadow]Number of cached networks: 10
Jul 11 17:28:48 beamcm kernel: [  157.271733] wilc_sdio mmc1:0001:1 wlan0: INFO [remove_network_from_shadow]Number of cached networks: 8
Jul 11 17:28:48 beamcm kernel: [  157.288140] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_set_bssid]set bssid on[7d41687c]
Jul 11 17:28:48 beamcm kernel: [  157.288157] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_set_bssid]set bssid [0][0][0]
Jul 11 17:28:48 beamcm kernel: [  157.288171] wilc_sdio mmc1:0001:1 p2p0: INFO [disconnect]Disconnecting with reason code(3)
Jul 11 17:28:48 beamcm kernel: [  157.751773] wilc_sdio mmc1:0001:1 wlan0: ERR [cfg_set:1808] Timed Out
Jul 11 17:28:48 beamcm kernel: [  157.751788] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_send_config_pkt:1903] Set Timed out
Jul 11 17:28:48 beamcm kernel: [  157.751803] wilc_sdio mmc1:0001:1 wlan0: ERR [handle_register_frame:2689] Failed to frame register
Jul 11 17:28:50 beamcm kernel: [  159.831766] wilc_sdio mmc1:0001:1 p2p0: INFO [debug_thread]*** Debug Thread Running ***
Jul 11 17:28:51 beamcm kernel: [  160.791779] wilc_sdio mmc1:0001:1 wlan0: ERR [cfg_set:1808] Timed Out
Jul 11 17:28:51 beamcm kernel: [  160.791795] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_send_config_pkt:1903] Set Timed out
Jul 11 17:28:51 beamcm kernel: [  160.791810] wilc_sdio mmc1:0001:1 wlan0: ERR [handle_register_frame:2689] Failed to frame register
Jul 11 17:28:54 beamcm kernel: [  163.831776] wilc_sdio mmc1:0001:1 wlan0: ERR [cfg_set:1808] Timed Out
Jul 11 17:28:54 beamcm kernel: [  163.831790] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_send_config_pkt:1903] Set Timed out
Jul 11 17:28:54 beamcm kernel: [  163.831804] wilc_sdio mmc1:0001:1 wlan0: ERR [handle_register_frame:2689] Failed to frame register
Jul 11 17:28:56 beamcm kernel: [  165.591734] wilc_sdio mmc1:0001:1 p2p0: INFO [remove_network_from_shadow]Number of cached networks: 10
Jul 11 17:28:57 beamcm kernel: [  166.231765] wilc_sdio mmc1:0001:1 p2p0: INFO [debug_thread]*** Debug Thread Running ***
Jul 11 17:28:57 beamcm kernel: [  166.871730] wilc_sdio mmc1:0001:1 wlan0: INFO [remove_network_from_shadow]Number of cached networks: 8
Jul 11 17:28:57 beamcm kernel: [  166.871749] wilc_sdio mmc1:0001:1 wlan0: ERR [cfg_set:1808] Timed Out
Jul 11 17:28:57 beamcm kernel: [  166.871764] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_send_config_pkt:1903] Set Timed out
Jul 11 17:28:57 beamcm kernel: [  166.871778] wilc_sdio mmc1:0001:1 wlan0: ERR [handle_register_frame:2689] Failed to frame register
Jul 11 17:29:00 beamcm kernel: [  169.911767] wilc_sdio mmc1:0001:1 wlan0: ERR [cfg_set:1808] Timed Out
Jul 11 17:29:00 beamcm kernel: [  169.911785] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_send_config_pkt:1903] Set Timed out
Jul 11 17:29:00 beamcm kernel: [  169.911800] wilc_sdio mmc1:0001:1 wlan0: ERR [handle_register_frame:2689] Failed to frame register
Jul 11 17:29:03 beamcm kernel: [  172.631775] wilc_sdio mmc1:0001:1 p2p0: INFO [debug_thread]*** Debug Thread Running ***
Jul 11 17:29:03 beamcm kernel: [  172.631786] wilc_sdio mmc1:0001:1 p2p0: INFO [debug_thread]<Recover>
Jul 11 17:29:03 beamcm kernel: [  172.631799] wilc_sdio mmc1:0001:1 wlan0: INFO [wilc_mac_close]Mac close
Jul 11 17:29:03 beamcm kernel: [  172.631810] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_close]Mac close
Jul 11 17:29:03 beamcm kernel: [  172.631819] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_close]Deinitializing wilc
Jul 11 17:29:03 beamcm kernel: [  172.631832] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]Deinitializing wilc  ...
Jul 11 17:29:03 beamcm kernel: [  172.631842] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]Disabling IRQ
Jul 11 17:29:03 beamcm kernel: [  172.631853] wilc_sdio mmc1:0001:1: wilc_sdio_disable_interrupt
Jul 11 17:29:03 beamcm kernel: [  172.631956] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]Deinitializing Threads
Jul 11 17:29:03 beamcm kernel: [  172.631967] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_deinitialize_threads]Deinitializing Threads
Jul 11 17:29:03 beamcm kernel: [  172.631978] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_deinitialize_threads]Deinitializing Threads
Jul 11 17:29:03 beamcm kernel: [  172.632039] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]Deinitializing IRQ
Jul 11 17:29:03 beamcm kernel: [  172.633162] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633172] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:03 beamcm kernel: [  172.633185] wilc_sdio mmc1:0001:1 wlan0: ERR [wilc_wlan_stop:1663] Error while reading reg
Jul 11 17:29:03 beamcm kernel: [  172.633236] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633246] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:03 beamcm kernel: [  172.633258] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_wlan_deinitialize:1039] failed in wlan_stop
Jul 11 17:29:03 beamcm kernel: [  172.633267] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]Deinitializing WILC Wlan
Jul 11 17:29:03 beamcm kernel: [  172.633299] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]Deinitializing Locks
Jul 11 17:29:03 beamcm kernel: [  172.633310] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_deinit_locks]De-Initializing Locks
Jul 11 17:29:03 beamcm kernel: [  172.633320] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_deinitialize]wilc deinitialization Done
Jul 11 17:29:03 beamcm kernel: [  172.633338] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_open]MAC OPEN[7d41687c] p2p0
Jul 11 17:29:03 beamcm kernel: [  172.633346] power up request for already powered up source Wifi
Jul 11 17:29:03 beamcm kernel: [  172.633352] Device already up. request source is Wifi
Jul 11 17:29:03 beamcm kernel: [  172.633363] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_open]*** re-init ***
Jul 11 17:29:03 beamcm kernel: [  172.633373] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_init_locks]Initializing Locks ...
Jul 11 17:29:03 beamcm kernel: [  172.633385] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_init]Initializing WILC_Wlan
Jul 11 17:29:03 beamcm kernel: [  172.633446] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633455] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:03 beamcm kernel: [  172.633505] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633515] wilc_sdio mmc1:0001:1: Failed cmd 52, write reg 000000f0 ...
Jul 11 17:29:03 beamcm kernel: [  172.633564] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633574] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:03 beamcm kernel: [  172.633623] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633632] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:03 beamcm kernel: [  172.633639] [wilc start]: fail read reg 0x3b0000
Jul 11 17:29:03 beamcm kernel: [  172.633688] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633697] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:03 beamcm kernel: [  172.633748] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633756] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:03 beamcm kernel: [  172.633767] wilc_sdio mmc1:0001:1 p2p0: ERR [init_chip:1925] fail read reg 0x1118
Jul 11 17:29:03 beamcm kernel: [  172.633817] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.633827] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:03 beamcm kernel: [  172.633844] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_wlan_initialize:1123] Initializing WILC_Wlan FAILED
Jul 11 17:29:03 beamcm kernel: [  172.633854] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_deinit_locks]De-Initializing Locks
Jul 11 17:29:03 beamcm kernel: [  172.633865] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_wlan_initialize:1204] WLAN initialization FAILED
Jul 11 17:29:03 beamcm kernel: [  172.633875] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_mac_open:1248] Failed to initialize wilc
Jul 11 17:29:03 beamcm kernel: [  172.751762] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_open]MAC OPEN[7d41687c] p2p0
Jul 11 17:29:03 beamcm kernel: [  172.751774] power up request for already powered up source Wifi
Jul 11 17:29:03 beamcm kernel: [  172.751780] Device already up. request source is Wifi
Jul 11 17:29:03 beamcm kernel: [  172.751790] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_open]*** re-init ***
Jul 11 17:29:03 beamcm kernel: [  172.751800] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_init_locks]Initializing Locks ...
Jul 11 17:29:03 beamcm kernel: [  172.751811] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_init]Initializing WILC_Wlan
Jul 11 17:29:03 beamcm kernel: [  172.751911] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.751921] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:03 beamcm kernel: [  172.751975] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.751984] wilc_sdio mmc1:0001:1: Failed cmd 52, write reg 000000f0 ...
Jul 11 17:29:03 beamcm kernel: [  172.752037] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.752046] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:03 beamcm kernel: [  172.752098] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
Jul 11 17:29:03 beamcm kernel: [  172.752107] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:03 beamcm kernel: [  172.752114] [wilc start]: fail read reg 0x3b0000
Jul 11 17:29:03 beamcm kernel: [  172.752166] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-110)
....
....
Jul 11 17:29:04 beamcm kernel: [  173.231738] power up request for already powered up source Wifi
Jul 11 17:29:04 beamcm kernel: [  173.231742] Device already up. request source is Wifi
Jul 11 17:29:04 beamcm kernel: [  173.231748] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_open]*** re-init ***
Jul 11 17:29:04 beamcm kernel: [  173.231753] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_init_locks]Initializing Locks ...
Jul 11 17:29:04 beamcm kernel: [  173.231761] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_wlan_init]Initializing WILC_Wlan
Jul 11 17:29:04 beamcm kernel: [  173.231796] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231801] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:04 beamcm kernel: [  173.231810] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231816] wilc_sdio mmc1:0001:1: Failed cmd 52, write reg 000000f0 ...
Jul 11 17:29:04 beamcm kernel: [  173.231823] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231829] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:04 beamcm kernel: [  173.231837] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231841] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:04 beamcm kernel: [  173.231846] [wilc start]: fail read reg 0x3b0000
Jul 11 17:29:04 beamcm kernel: [  173.231853] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231858] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:04 beamcm kernel: [  173.231865] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231869] wilc_sdio mmc1:0001:1: Failed cmd52, set 0x10c data...
Jul 11 17:29:04 beamcm kernel: [  173.231875] wilc_sdio mmc1:0001:1 p2p0: ERR [init_chip:1925] fail read reg 0x1118
Jul 11 17:29:04 beamcm kernel: [  173.231883] wilc_sdio mmc1:0001:1: wilc_sdio_cmd52..failed, err(-123)
Jul 11 17:29:04 beamcm kernel: [  173.231889] wilc_sdio mmc1:0001:1: Failed cmd 52, read reg (000000f0) ...
Jul 11 17:29:04 beamcm kernel: [  173.231901] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_wlan_initialize:1123] Initializing WILC_Wlan FAILED
Jul 11 17:29:04 beamcm kernel: [  173.231907] wilc_sdio mmc1:0001:1 p2p0: INFO [wlan_deinit_locks]De-Initializing Locks
Jul 11 17:29:04 beamcm kernel: [  173.231912] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_wlan_initialize:1204] WLAN initialization FAILED
Jul 11 17:29:04 beamcm kernel: [  173.231919] wilc_sdio mmc1:0001:1 p2p0: ERR [wilc_mac_open:1248] Failed to initialize wilc
Jul 11 17:29:04 beamcm kernel: [  173.351736] wilc_sdio mmc1:0001:1 p2p0: INFO [wilc_mac_open]MAC OPEN[7d41687c] p2p0
Jul 11 17:29:04 beamcm kernel: [  173.351746] power up request for already powered up source Wifi

And it repeats again and again the last few lines. If you want all the log file, you can find it here : https://www.filehosting.org/file/details/811367/log.txt

When I power the atwilc3000 after the boot with dhcpcd enables, the driver seems to initialize both interfaces (I can see wlan0 and p2p0 with ifconfig). But after a moment, the system start to crash with this "-123" error.

If a run ifconfig p2p0 down and ifconfig wlan0 down before this crash, I'm able to use the Bluetooth module with dhcpcd enable. There might be a problem if we let those interfaces up at startup. To get around this problem, I added "sudo ifconfig p2p0 down and sudo ifconfig wlan0 down" in /etc/rc.local. I will use this workaround for the moment. I'll made more test once I get my pcb with the atwilc3000.

Another unrelated question: is it possible to query the Bluetooth module to see if there has been a problem or if it is still working?

AdhamAbozaeid commented 5 years ago

The cause of SDIO errors is either the SDIO connection, or powersave. I recommend that you disable powersave either by disabling the CONFIG_CFG80211_DEFAULT_PS flag in the kernel .config file, or override the "enabled" value in wilc_set_power_mgmt() to always be WILC_FW_NO_POWERSAVE.

To query the BLE module, maybe you can send any HCI command and see if it returns correct values, maybe an HCI to read the supported features (OGF 0x08, OCF 0x0003)

AntoineBore commented 5 years ago

or override the "enabled" value in wilc_set_power_mgmt() to always be WILC_FW_NO_POWERSAVE.

This works for me with the value is "NO_POWERSAVE" and not "WILC_FW_NO_POWERSAVE" as I use the driver from this repository and not the Linux one. But maybe I should change that as the master has not been updated for 6 months here ?

That is what I wanted to do but I use python and pybluez to control the module and it doesn't seem to have such output. Anyway, I'll keep looking for a nice solution.

Thank you for your help. I'll update this status when I receive my pcb with the ATWILC3000 solder.

AdhamAbozaeid commented 5 years ago

It won't matter for now whether you use the master or the dev branch. Once the dev branch is ready for releasing, it will be merged back to master. My estimate is that this should happen sometime around September.

AdhamAbozaeid commented 4 years ago

@AntoineBore , are you still having the same issue with release 15.3?