Failing to connect (Pico W)

Hey there. I've been trying to connect to a couple wifi routers I have, and most recently to my phone hotspot (Pixel 6, because I can put it right next to the Pico, which gives more consistent results). I haven't succeeded yet. A typical log is below.

Sometimes it also freezes after "set country".

I was able to run the scanning example successfully. With AP example I couldn't find or connect to the network with my laptop.

Happy to take a patch and run it for the output, if it helps. This log is on current master (6ee45f5ec01208bdcb38f23bf46dcdac141ff6e7).

Logs

``` 0.001125 INFO Hello World! └─ src/bin/tcp_server.rs:47 0.272577 INFO waiting for clock... └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.272650 INFO clock ok └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.272874 INFO chip ID: 43439 └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.275712 INFO loading fw └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.427551 INFO loading nvram └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.428379 INFO starting up core... └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.570283 INFO IOCTL Response: [00, 00, 00, 00, 6f, 61, 64, 5f, 73, 74, 61, 74, 75, 73, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.570354 INFO IOCTL Response: [00, 00, 00, 00, 6f, 61, 64, 5f, 73, 74, 61, 74, 75, 73, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.570649 INFO Configuring misc stuff... └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.570705 INFO set bus:txglom = [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.571510 INFO IOCTL Response: [62, 75, 73, 3a, 74, 78, 67, 6c, 6f, 6d, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.571577 INFO IOCTL Response: [62, 75, 73, 3a, 74, 78, 67, 6c, 6f, 6d, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.571892 INFO set apsta = [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.572604 INFO IOCTL Response: [61, 70, 73, 74, 61, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.572662 INFO IOCTL Response: [61, 70, 73, 74, 61, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.572950 INFO get cur_etheraddr └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.573644 INFO IOCTL Response: [28, cd, c1, 0b, 30, 67, 68, 65, 72, 61, 64, 64, 72, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.573719 INFO IOCTL Response: [28, cd, c1, 0b, 30, 67, 68, 65, 72, 61, 64, 64, 72, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.573999 INFO mac addr: [28, cd, c1, 0b, 30, 67] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 0.574074 INFO set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.888112 INFO IOCTL Response: [63, 6f, 75, 6e, 74, 72, 79, 00, 58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.888194 INFO IOCTL Response: [63, 6f, 75, 6e, 74, 72, 79, 00, 58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.889044 DEBUG LOGS: 000000.721 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out └─ /Users/tyler/code/cyw43/src/fmt.rs:127 1.889222 DEBUG LOGS: 000000.837 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out └─ /Users/tyler/code/cyw43/src/fmt.rs:127 1.889564 DEBUG LOGS: 000000.961 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframd └─ /Users/tyler/code/cyw43/src/fmt.rs:127 1.889741 DEBUG LOGS: 000001.427 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframe └─ /Users/tyler/code/cyw43/src/fmt.rs:127 1.889916 DEBUG LOGS: 000001.434 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for uxcrs └─ /Users/tyler/code/cyw43/src/fmt.rs:127 1.890126 WARN IRQ DATA_UNAVAILABLE, clearing... └─ /Users/tyler/code/cyw43/src/fmt.rs:153 1.989155 INFO IOCTL Response: [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.989196 INFO IOCTL Response: [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.989471 INFO set bus:txglom = [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.990216 INFO IOCTL Response: [62, 75, 73, 3a, 74, 78, 67, 6c, 6f, 6d, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 1.990284 INFO IOCTL Response: [62, 75, 73, 3a, 74, 78, 67, 6c, 6f, 6d, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.090597 INFO set ampdu_ba_wsize = [08, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.091340 INFO IOCTL Response: [61, 6d, 70, 64, 75, 5f, 62, 61, 5f, 77, 73, 69, 7a, 65, 00, 08, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.091417 INFO IOCTL Response: [61, 6d, 70, 64, 75, 5f, 62, 61, 5f, 77, 73, 69, 7a, 65, 00, 08, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.191745 INFO set ampdu_mpdu = [04, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.192490 INFO IOCTL Response: [61, 6d, 70, 64, 75, 5f, 6d, 70, 64, 75, 00, 04, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.192560 INFO IOCTL Response: [61, 6d, 70, 64, 75, 5f, 6d, 70, 64, 75, 00, 04, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.292884 INFO set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.293687 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 65, 76, 65, 6e, 74, 5f, 6d, 73, 67, 73, 00, 00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.293830 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 65, 76, 65, 6e, 74, 5f, 6d, 73, 67, 73, 00, 00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.395387 INFO IOCTL Response: [] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.395422 INFO IOCTL Response: [] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.395464 WARN IRQ DATA_UNAVAILABLE, clearing... └─ /Users/tyler/code/cyw43/src/fmt.rs:153 2.396153 DEBUG LOGS: 000001.942 wl0: wl_open └─ /Users/tyler/code/cyw43/src/fmt.rs:127 2.396306 WARN IRQ DATA_UNAVAILABLE, clearing... └─ /Users/tyler/code/cyw43/src/fmt.rs:153 2.496288 INFO IOCTL Response: [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.496332 INFO IOCTL Response: [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.497222 INFO IOCTL Response: [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.497262 INFO IOCTL Response: [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.597557 INFO INIT DONE └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.597607 INFO set pm2_sleep_ret = [c8, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.598378 INFO IOCTL Response: [70, 6d, 32, 5f, 73, 6c, 65, 65, 70, 5f, 72, 65, 74, 00, c8, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.598456 INFO IOCTL Response: [70, 6d, 32, 5f, 73, 6c, 65, 65, 70, 5f, 72, 65, 74, 00, c8, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.598785 INFO set bcn_li_bcn = [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.599501 INFO IOCTL Response: [62, 63, 6e, 5f, 6c, 69, 5f, 62, 63, 6e, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.599571 INFO IOCTL Response: [62, 63, 6e, 5f, 6c, 69, 5f, 62, 63, 6e, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.599858 INFO set bcn_li_dtim = [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.600568 INFO IOCTL Response: [62, 63, 6e, 5f, 6c, 69, 5f, 64, 74, 69, 6d, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.600640 INFO IOCTL Response: [62, 63, 6e, 5f, 6c, 69, 5f, 64, 74, 69, 6d, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.600937 INFO set assoc_listen = [0a, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.601674 INFO IOCTL Response: [61, 73, 73, 6f, 63, 5f, 6c, 69, 73, 74, 65, 6e, 00, 0a, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.601748 INFO IOCTL Response: [61, 73, 73, 6f, 63, 5f, 6c, 69, 73, 74, 65, 6e, 00, 0a, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.602691 INFO IOCTL Response: [02, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.602734 INFO IOCTL Response: [02, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.603198 DEBUG Acquired IP configuration: └─ /Users/tyler/.cargo/git/checkouts/embassy-9312dcb0ed774b29/03d6363/embassy-net/src/fmt.rs:125 2.603218 DEBUG IP address: 192.168.1.69/24 └─ /Users/tyler/.cargo/git/checkouts/embassy-9312dcb0ed774b29/03d6363/embassy-net/src/fmt.rs:125 2.603331 DEBUG Default gateway: 192.168.1.1 └─ /Users/tyler/.cargo/git/checkouts/embassy-9312dcb0ed774b29/03d6363/embassy-net/src/fmt.rs:125 2.603460 INFO set ampdu_ba_wsize = [08, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.604410 INFO IOCTL Response: [61, 6d, 70, 64, 75, 5f, 62, 61, 5f, 77, 73, 69, 7a, 65, 00, 08, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.604498 INFO IOCTL Response: [61, 6d, 70, 64, 75, 5f, 62, 61, 5f, 77, 73, 69, 7a, 65, 00, 08, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.605532 INFO IOCTL Response: [04, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.605575 INFO IOCTL Response: [04, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.605913 INFO set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.606662 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 73, 75, 70, 5f, 77, 70, 61, 00, 00, 00, 00, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.606748 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 73, 75, 70, 5f, 77, 70, 61, 00, 00, 00, 00, 00, 01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.607092 INFO set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.607851 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 73, 75, 70, 5f, 77, 70, 61, 32, 5f, 65, 61, 70, 76, 65, 72, 00, 00, 00, 00, 00, ff, ff, ff, ff] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.607960 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 73, 75, 70, 5f, 77, 70, 61, 32, 5f, 65, 61, 70, 76, 65, 72, 00, 00, 00, 00, 00, ff, ff, ff, ff] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.608311 INFO set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.609054 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 73, 75, 70, 5f, 77, 70, 61, 5f, 74, 6d, 6f, 00, 00, 00, 00, 00, c4, 09, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.609149 INFO IOCTL Response: [62, 73, 73, 63, 66, 67, 3a, 73, 75, 70, 5f, 77, 70, 61, 5f, 74, 6d, 6f, 00, 00, 00, 00, 00, c4, 09, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.710174 INFO IOCTL Response: [0c, 00, 01, 00, 73, 75, 6e, 6e, 79, 76, 61, 73, 65, 30, 36, 31, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.710303 INFO IOCTL Response: [0c, 00, 01, 00, 73, 75, 6e, 6e, 79, 76, 61, 73, 65, 30, 36, 31, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.711299 INFO IOCTL Response: [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.711341 INFO IOCTL Response: [01, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.712240 INFO IOCTL Response: [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.712281 INFO IOCTL Response: [00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.713164 INFO IOCTL Response: [80, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.713204 INFO IOCTL Response: [80, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.714367 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 2.714461 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 6.858057 DEBUG === EVENT ASSOC_REQ_IE: EventMessage { version: 2, flags: 0, event_type: 87, status: 0, reason: 0, auth_type: 0, datalen: 81, addr: [21, 88, 4f, 21, f6, 1b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [00, 0d, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 01, 08, 82, 84, 8b, 96, 24, 30, 48, 6c, 32, 04, 0c, 12, 18, 60, 21, 02, 05, 17, 24, 02, 01, 0e, 30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 0c, 00, dd, 09, 00, 10, 18, 02, 00, 00, 00, 00, 00, dd, 07, 00, 50, f2, 02, 00, 01, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 6.858472 WARN unexpected ethernet type 0x887e, expected Broadcom ether type 0x886c └─ /Users/tyler/code/cyw43/src/fmt.rs:153 6.859427 DEBUG LOGS: 000005.809 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed nut └─ /Users/tyler/code/cyw43/src/fmt.rs:127 6.859598 DEBUG LOGS: 000005.926 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out └─ /Users/tyler/code/cyw43/src/fmt.rs:127 6.859768 DEBUG LOGS: 000006.043 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement tiled out └─ /Users/tyler/code/cyw43/src/fmt.rs:127 6.860285 DEBUG LOGS: 000006.380 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for txcrs └─ /Users/tyler/code/cyw43/src/fmt.rs:127 6.867720 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 6, reason: 0, auth_type: 0, datalen: 0, addr: [a, 2a, db, 49, 15, c1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 6.868160 WARN JOIN failed with status=6 └─ /Users/tyler/code/cyw43/src/fmt.rs:153 6.869083 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 6.869178 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 6.869379 DEBUG === EVENT ASSOC: EventMessage { version: 2, flags: 0, event_type: 7, status: 4, reason: 0, auth_type: 0, datalen: 0, addr: [a, 2a, db, 49, 15, c1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 9.683786 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [a, 2a, db, 49, 15, c1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 9.683999 WARN JOIN failed with status=5 └─ /Users/tyler/code/cyw43/src/fmt.rs:153 9.684083 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [6c, dd, a, 0, 10, 18], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 9.685138 DEBUG LOGS: 000009.211 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframe └─ /Users/tyler/code/cyw43/src/fmt.rs:127 9.685312 DEBUG LOGS: 000009.219 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for txbrs └─ /Users/tyler/code/cyw43/src/fmt.rs:127 9.685471 DEBUG LOGS: 000009.222 wl0: JOIN: authentication failure, no ack └─ /Users/tyler/code/cyw43/src/fmt.rs:127 9.686151 WARN IRQ DATA_UNAVAILABLE, clearing... └─ /Users/tyler/code/cyw43/src/fmt.rs:153 9.698651 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 9.698745 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 11.460311 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [a, 2a, db, 49, 15, c1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 11.460512 WARN JOIN failed with status=5 └─ /Users/tyler/code/cyw43/src/fmt.rs:153 11.460588 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 0, 0, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 11.461773 DEBUG LOGS: 000010.896 wl0: wlc_lcn20phy_rx_hq_est: IQ measurement timed out └─ /Users/tyler/code/cyw43/src/fmt.rs:127 11.462624 WARN IRQ DATA_UNAVAILABLE, clearing... └─ /Users/tyler/code/cyw43/src/fmt.rs:153 11.463904 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 11.463999 INFO IOCTL Response: [0d, 00, 00, 00, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:140 13.509920 DEBUG === EVENT ASSOC_REQ_IE: EventMessage { version: 2, flags: 0, event_type: 87, status: 0, reason: 0, auth_type: 0, datalen: 81, addr: [0, 0, 18, 10, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [00, 0d, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 01, 08, 82, 84, 8b, 96, 24, 30, 48, 6c, 32, 04, 0c, 12, 18, 60, 21, 02, 05, 17, 24, 02, 01, 0e, 30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 0c, 00, dd, 09, 00, 10, 18, 02, 00, 00, 00, 00, 00, dd, 07, 00, 50, f2, 02, 00, 01, 00] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 13.510265 WARN len inv mismatch └─ /Users/tyler/code/cyw43/src/fmt.rs:153 13.512246 WARN IRQ DATA_UNAVAILABLE, clearing... └─ /Users/tyler/code/cyw43/src/fmt.rs:153 13.591615 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [a, 2a, db, 49, 15, c1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 13.591796 DEBUG === EVENT ASSOC: EventMessage { version: 2, flags: 0, event_type: 7, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [a, 2a, db, 49, 15, c1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 13.591972 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, a, 2a, db, 49], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] └─ /Users/tyler/code/cyw43/src/fmt.rs:127 ```

For reference, this is what it looks like when it works for me

> 0.001140 INFO Hello World! > 0.272594 INFO waiting for clock... > 0.272669 INFO clock ok > 0.272887 INFO chip ID: 43439 > 0.275702 INFO loading fw > 0.427820 INFO loading nvram > 0.428670 INFO starting up core... > 0.449888 INFO waiting for wifi init... > 0.534052 INFO shared_addr 00016070 > 0.534316 INFO init done > 0.534619 INFO Downloading CLM... > 0.536175 DEBUG LOGS: 000000.001 > 0.536443 DEBUG LOGS: 000000.003 sdpcmdcdc0: Broadcom SDPCMD CDC driver > 0.537560 DEBUG LOGS: 000000.056 TCAM: 256 used: 76 exceed:0 > 0.538497 WARN TX stalled > 0.538826 WARN BCD event, incomplete data > 0.538919 WARN BCD event, incomplete data > 0.547160 INFO get clmload_status > 0.548053 INFO Configuring misc stuff... > 0.548110 INFO set bus:txglom = [00, 00, 00, 00] > 0.549138 INFO set apsta = [01, 00, 00, 00] > 0.550057 INFO get cur_etheraddr > 0.550870 INFO mac addr: [28, cd, c1, 06, bc, 50] > 0.550945 INFO set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] > 0.680540 INFO set bus:txglom = [00, 00, 00, 00] > 0.781465 INFO set ampdu_ba_wsize = [08, 00, 00, 00] > 0.882399 INFO set ampdu_mpdu = [04, 00, 00, 00] > 0.983340 INFO set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] > 1.085533 WARN IRQ DATA_UNAVAILABLE, clearing... > 1.086255 DEBUG LOGS: 000000.627 wl0: wl_open > 1.086368 WARN IRQ DATA_UNAVAILABLE, clearing... > 1.287280 INFO INIT DONE > 1.287339 INFO set pm2_sleep_ret = [c8, 00, 00, 00] > 1.288306 INFO set bcn_li_bcn = [01, 00, 00, 00] > 1.289219 INFO set bcn_li_dtim = [01, 00, 00, 00] > 1.290134 INFO set assoc_listen = [0a, 00, 00, 00] > 1.292155 INFO set ampdu_ba_wsize = [08, 00, 00, 00] > 1.296070 INFO set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00] > 1.297104 INFO set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff] > 1.298056 INFO set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00] > 4.413767 DEBUG === EVENT ASSOC_REQ_IE: EventMessage { version: 2, flags: 0, event_type: 87, status: 0, reason: 0, auth_type: 0, datalen: 79, addr: [f, 1, c2, 20, 56, 3c], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [00, 0b, 57, 4c, 41, 4e, 4e, 45, 54, 31, 35, 35, 35, 01, 08, 82, 84, 8b, 96, 24, b0, 48, 6c, 32, 04, 8c, 12, 98, 60, 21, 02, 05, 17, 24, 02, 01, 0e, 30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 0c, 00, dd, 09, 00, 10, 18, 02, 00, 00, 00, 00, 00, dd, 07, 00, 50, f2, 02, 00, 01, 00] > 4.414203 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 0, reason: 0, auth_type: 0, datalen: 0, addr: [e0, 28, 6d, fa, 30, a1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] > 4.419125 DEBUG === EVENT ASSOC_RESP_IE: EventMessage { version: 2, flags: 0, event_type: 88, status: 0, reason: 0, auth_type: 0, datalen: 95, addr: [10, 0, d6, 26, d7, 30], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [01, 08, 82, 84, 8b, 0c, 12, 96, 18, 24, 32, 04, 30, 48, 60, 6c, 46, 05, 73, d0, 00, 00, 0c, 7f, 08, 05, 00, 0f, 00, 00, 00, 00, 40, dd, 18, 00, 50, f2, 02, 01, 01, 00, 00, 03, a4, 00, 00, 27, a4, 00, 00, 42, 43, 5e, 00, 62, 32, 2f, 00, dd, 08, 8c, fd, f0, 01, 01, 02, 01, 00, dd, 18, 00, 50, f2, 04, 10, 4a, 00, 01, 10, 10, 3b, 00, 01, 03, 10, 49, 00, 06, 00, 37, 2a, 00, 01, 20] > 4.419546 DEBUG === EVENT ASSOC: EventMessage { version: 2, flags: 0, event_type: 7, status: 0, reason: 0, auth_type: 0, datalen: 101, addr: [e0, 28, 6d, fa, 30, a1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [31, 14, 00, 00, 04, c0, 01, 08, 82, 84, 8b, 0c, 12, 96, 18, 24, 32, 04, 30, 48, 60, 6c, 46, 05, 73, d0, 00, 00, 0c, 7f, 08, 05, 00, 0f, 00, 00, 00, 00, 40, dd, 18, 00, 50, f2, 02, 01, 01, 00, 00, 03, a4, 00, 00, 27, a4, 00, 00, 42, 43, 5e, 00, 62, 32, 2f, 00, dd, 08, 8c, fd, f0, 01, 01, 02, 01, 00, dd, 18, 00, 50, f2, 04, 10, 4a, 00, 01, 10, 10, 3b, 00, 01, 03, 10, 49, 00, 06, 00, 37, 2a, 00, 01, 20] > 4.420553 DEBUG LOGS: 000003.949 wl0: link up (wl0) > 4.420784 DEBUG === EVENT LINK: EventMessage { version: 2, flags: 1, event_type: 16, status: 0, reason: 0, auth_type: 0, datalen: 22, addr: [e0, 28, 6d, fa, 30, a1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 00, 00] > 4.420950 WARN IRQ DATA_UNAVAILABLE, clearing... > 4.423603 DEBUG === EVENT JOIN: EventMessage { version: 2, flags: 0, event_type: 1, status: 0, reason: 0, auth_type: 0, datalen: 0, addr: [e0, 28, 6d, fa, 30, a1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] > 4.423840 INFO JOINED > 4.424163 INFO set gpioout = [01, 00, 00, 00, 00, 00, 00, 00] > 4.424346 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 0, reason: 0, auth_type: 0, datalen: 11, addr: [e0, 28, 6d, fa, 30, a1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [57, 4c, 41, 4e, 4e, 45, 54, 31, 35, 35, 35] > 4.425035 INFO link_up = true > 4.425106 DEBUG Lost IP configuration > 4.425823 INFO Listening on TCP:1234... > 4.447491 DEBUG === EVENT PSK_SUP: EventMessage { version: 2, flags: 0, event_type: 46, status: 6, reason: 0, auth_type: 0, datalen: 0, addr: [0, 0, c, e, 5, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] > 11.303648 DEBUG Acquired IP configuration: > 11.303679 DEBUG IP address: 192.168.178.26/24 > 11.303783 DEBUG Default gateway: 192.168.178.1 > 11.303844 DEBUG DNS server 0: 192.168.178.1

Unfortunately debugging this chip is really difficult since there isn't really any documentation beyond the SPI interface.

I noticed two things so far:

6.858472 WARN unexpected ethernet type 0x887e, expected Broadcom ether type 0x886c
you get an IP really early, did you set a static ip?

there is currently a loop that simply retries the join, if it fails. So events beyond the first join failure may not be helpful.

And, if you don't mind, I just made a commit to remove the IOCTL RESPONSE spam, could you re-post the logs (maybe also with debug=1 to remove the 2nd line)? That makes it a bit more readable.

I did set a static ip initially to see if DHCP was the problem. Reverted that now. I had to switch to using probe-run to get rid of the line number spam.

Log (not that interesting, see below)

``` 0.001140 INFO Hello World! 0.272576 INFO waiting for clock... 0.272652 INFO clock ok 0.272888 INFO chip ID: 43439 0.275779 INFO loading fw 0.427742 INFO loading nvram 0.428580 INFO starting up core... 0.449847 INFO waiting for wifi init... 0.533964 INFO shared_addr 00016070 0.534238 INFO init done 0.534543 INFO Downloading CLM... 0.536098 DEBUG LOGS: 000000.001 0.536367 DEBUG LOGS: 000000.003 sdpcmdcdc0: Broadcom SDPCMD CDC driver 0.537485 DEBUG LOGS: 000000.056 TCAM: 256 used: 76 exceed:0 0.538431 WARN TX stalled 0.538752 WARN BCD event, incomplete header 0.538846 WARN BCD event, incomplete header 0.547734 INFO get clmload_status 0.548771 INFO Configuring misc stuff... 0.548827 INFO set bus:txglom = [00, 00, 00, 00] 0.549942 INFO set apsta = [01, 00, 00, 00] 0.550946 INFO get cur_etheraddr 0.551868 INFO mac addr: [28, cd, c1, 0b, 30, 67] 0.551940 INFO set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] 1.626498 DEBUG LOGS: 000000.468 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 1.626686 DEBUG LOGS: 000000.594 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 1.627047 DEBUG LOGS: 000000.713 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframd 1.627232 DEBUG LOGS: 000000.720 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for txcrs 1.627433 DEBUG LOGS: 000000.721 wl0: wlc_lcn20phy_idle_tssi_est, ERROR: idleTssi estPwr(OB): 0x0000 Register avgTssi(OB, 7MSB): 0x0040 1.627747 WARN IRQ DATA_UNAVAILABLE, clearing... 1.726843 INFO set bus:txglom = [00, 00, 00, 00] 1.827868 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 1.928908 INFO set ampdu_mpdu = [04, 00, 00, 00] 2.029939 INFO set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] 2.132252 WARN IRQ DATA_UNAVAILABLE, clearing... 2.133129 WARN IRQ DATA_UNAVAILABLE, clearing... 2.334238 INFO INIT DONE 2.334290 INFO set pm2_sleep_ret = [c8, 00, 00, 00] 2.335325 INFO set bcn_li_bcn = [01, 00, 00, 00] 2.336306 INFO set bcn_li_dtim = [01, 00, 00, 00] 2.337285 INFO set assoc_listen = [0a, 00, 00, 00] 2.339432 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 2.340040 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3920894729, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 2.344058 INFO set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00] 2.345121 INFO set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff] 2.346125 INFO set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00] 3.264811 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 3, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 0, 0, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] 12.339256 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3614810059, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } ```

after that it's the same DHCP message repeated, until...

132.341008 WARN  unexpected ethernet type 0x0000, expected Broadcom ether type 0x886c

I've noticed these messages cropping up, this time it failed before that though.

Actually here's a more interesting log, I think the AP was turned off the first time, oops.

0.001138 INFO  Hello World!
0.272596 INFO  waiting for clock...
0.272675 INFO  clock ok
0.272896 INFO  chip ID: 43439
0.275674 INFO  loading fw
0.427550 INFO  loading nvram
0.428369 INFO  starting up core...
0.449586 INFO  waiting for wifi init...
0.533745 INFO  shared_addr 00016070
0.534021 INFO  init done 
0.534328 INFO  Downloading CLM...
0.535917 DEBUG LOGS: 000000.001 
0.536186 DEBUG LOGS: 000000.003 sdpcmdcdc0: Broadcom SDPCMD CDC driver
0.537305 DEBUG LOGS: 000000.056 TCAM: 256 used: 76 exceed:0
0.538239 WARN  TX stalled
0.538563 WARN  BCD event, incomplete header
0.538658 WARN  BCD event, incomplete header
0.547694 INFO  get clmload_status
0.548780 INFO  Configuring misc stuff...
0.548837 INFO  set bus:txglom = [00, 00, 00, 00]
0.549984 INFO  set apsta = [01, 00, 00, 00]
0.551008 INFO  get cur_etheraddr
0.551958 INFO  mac addr: [28, cd, c1, 0b, 30, 67]
0.552032 INFO  set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00]
1.721783 DEBUG LOGS: 000000.586 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out
1.721972 DEBUG LOGS: 000000.702 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out
1.722334 DEBUG LOGS: 000000.824 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframd
1.722586 WARN  IRQ DATA_UNAVAILABLE, clearing...
1.822182 INFO  set bus:txglom = [00, 00, 00, 00]
1.923243 INFO  set ampdu_ba_wsize = [08, 00, 00, 00]
2.024294 INFO  set ampdu_mpdu = [04, 00, 00, 00]
2.125368 INFO  set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff]
2.227730 WARN  IRQ DATA_UNAVAILABLE, clearing...
2.228486 DEBUG LOGS: 000001.772 wl0: wl_open
2.228653 WARN  IRQ DATA_UNAVAILABLE, clearing...
2.429843 INFO  INIT DONE
2.429889 INFO  set pm2_sleep_ret = [c8, 00, 00, 00]
2.430963 INFO  set bcn_li_bcn = [01, 00, 00, 00]
2.432000 INFO  set bcn_li_dtim = [01, 00, 00, 00]
2.433038 INFO  set assoc_listen = [0a, 00, 00, 00]
2.435282 INFO  set ampdu_ba_wsize = [08, 00, 00, 00]
2.435878 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3920894729, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] }
2.439995 INFO  set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00]
2.441094 INFO  set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff]
2.442147 INFO  set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00]
6.212146 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [d6, cd, 5b, ef, 3a, fa], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  []
6.212377 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [d6, cd, 5b, ef, 3a, fa], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  []
6.212701 WARN  JOIN failed with status=5
6.212801 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 0, 0, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c]
6.215135 WARN  IRQ DATA_UNAVAILABLE, clearing...
8.044082 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [d6, cd, 5b, ef, 3a, fa], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  []
8.044267 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [d6, cd, 5b, ef, 3a, fa], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  []
8.044508 WARN  JOIN failed with status=5
8.044590 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 0, 0, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c]
8.045983 DEBUG LOGS: 000007.064 wl0: wlc_lcn20phy_rx_hq_est: IQ measurement timed out
8.047518 WARN  IRQ DATA_UNAVAILABLE, clearing...
10.933493 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [d6, cd, 5b, ef, 3a, fa], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  []
10.933673 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [d6, cd, 5b, ef, 3a, fa], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  []
10.933913 WARN  JOIN failed with status=5
10.933988 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, b0, 0, 3a, 1], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, }  [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c]
10.935004 DEBUG LOGS: 000008.782 wl0: wlc_lcn20phy_rx_iq_est: IQ meastrement timed out
10.936087 DEBUG LOGS: 000009.480 wl0: wlc_lcn20phy_rx_iq_dst: IQ measurement timed out
10.936707 DEBUG LOGS: 000009.734 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out
10.936888 DEBUG LOGS: 000009.852 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timdd out
10.952764 DEBUG LOGS: 000010.467 wl0: JOIN: authentication failure, no ack
10.953454 WARN  IRQ DATA_UNAVAILABLE, clearing...
12.435270 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3614810059, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] }

Thanks. Yes, SET_SSID event with status=3 means no network found. This one fails with AUTH status=5 which means NO_ACK.

This is kind of a long shot but since this is the main part I contributed here recently... Can you see if it works with this branch https://github.com/kbleeke/cyw43/tree/slow-pio ? This one reduces the transmission speed between the pico and the wifi chip. I'm curious because there is weird data in a bunch of places: the ethernet type, len inv mismatch, weird typos (?) in firmware logs...

Oh and: did you try one of the official wifi examples from pico-sdk?

Log 1

``` 0.001139 INFO Hello World! 0.274336 INFO waiting for clock... 0.274675 INFO clock ok 0.275741 INFO chip ID: 43439 0.281428 INFO loading fw 4.434862 INFO loading nvram 4.449558 INFO starting up core... 4.473064 INFO waiting for wifi init... 4.557757 INFO shared_addr 00016070 4.559063 INFO init done 4.559366 INFO Downloading CLM... 4.580765 DEBUG LOGS: hndarm_armr addr: 0x18003000, cr4_idx: 0 4.580894 DEBUG LOGS: 000000.001 4.580979 DEBUG LOGS: RTE (SDIO-CDC) 7.95.50 (fb3ea36 CY) on BCM43439 r5 @ 37.4/81.6/81.6MHz 4.581163 DEBUG LOGS: 000000.003 sdpcmdcdc0: Broadcom SDPCMD CDC driver 4.581315 DEBUG LOGS: 000000.007 reclaim section 0: Returned 45968 bytes to the heap 4.581481 DEBUG LOGS: 000000.011 wlc_bmac_info_init: host_enab 1 4.581630 DEBUG LOGS: 000000.037 wl0: wlc_ampdu_tx_set: AGG Mode = MAC+Ucode txmaxpkts 64 txmaxpkts_agg 0 4.581856 DEBUG LOGS: 000000.049 wl0: wlc_channels_commit: no valid channel for "#n" nbands 1 bandlocked 0 4.582082 DEBUG LOGS: 000000.053 wl0: Broadcom BCM43439 802.11 Wireless Controller 7.95.50 (fb3ea36 CY) 4.582282 DEBUG LOGS: 000000.056 TCAM: 256 used: 76 exceed:0 4.582413 DEBUG LOGS: 000000.058 reclaim section 1: Returned 86112 bytes to the heap 4.616217 WARN TX stalled 4.620923 WARN BCD event, incomplete data 4.625192 WARN BCD event, incomplete data 4.843569 INFO get clmload_status 4.882125 INFO Configuring misc stuff... 4.882186 INFO set bus:txglom = [00, 00, 00, 00] 4.920703 INFO set apsta = [01, 00, 00, 00] 4.959246 INFO get cur_etheraddr 4.997781 INFO mac addr: [28, cd, c1, 0b, 30, 67] 4.997855 INFO set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] 6.322939 DEBUG LOGS: 000001.123 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 6.323126 DEBUG LOGS: 000001.239 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 6.323306 DEBUG LOGS: 000001.356 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 6.440911 INFO set bus:txglom = [00, 00, 00, 00] 6.579522 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 6.717889 INFO set ampdu_mpdu = [04, 00, 00, 00] 6.856248 INFO set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] 7.047915 DEBUG LOGS: 000002.518 wl0: wl_open 7.329242 INFO INIT DONE 7.329292 INFO set pm2_sleep_ret = [c8, 00, 00, 00] 7.367626 INFO set bcn_li_bcn = [01, 00, 00, 00] 7.406154 INFO set bcn_li_dtim = [01, 00, 00, 00] 7.444636 INFO set assoc_listen = [0a, 00, 00, 00] 7.521948 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 7.522586 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3920894729, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 7.632794 INFO set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00] 7.671277 INFO set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff] 7.709798 INFO set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00] 12.248956 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [36, e, 13, 25, 7e, 4b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 12.249346 WARN JOIN failed with status=2 12.253556 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 36, e, 13, 25], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] 12.274085 DEBUG LOGS: 000006.967 wlc_lcn20phy_rx_iq_cal_txrxgain_control: Too much or too little power? (gain_index=14) 12.274339 DEBUG LOGS: 000007.087 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 12.274520 DEBUG LOGS: 000007.204 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 12.274701 DEBUG LOGS: 000007.320 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 12.274882 DEBUG LOGS: 000007.322 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframe 12.275066 DEBUG LOGS: 000007.329 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for txcrs 12.275265 DEBUG LOGS: 000007.330 wl0: wlc_lcn20phy_idle_tssi_est, ERROR: idleTssi estPwr(OB): 0x002a Register avgTssi(OB, 7MSB): 0x0065 12.275552 DEBUG LOGS: 000007.750 wl0: wlc_bmac_suspend_mac_and_wait: waited 83000 uS and MI_MACSSPNDD is still not on. 12.275796 DEBUG LOGS: 000007.752 wl0: psmdebug 0x00ff80b5, phydebug 0x00000045, psm_brc 0x0080 17.522280 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3614810059, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 17.577133 DEBUG LOGS: OR: idleTssi estPwr(OB): 0x00bb Register avgTssi(OB, 7MSB): 0x0000 17.577337 DEBUG LOGS: 000008.511 wl0: wlc_dpc HAMMERING fatal txs err 17.577480 DEBUG LOGS: 000008.513 wl0: fatal error, reinitializing 27.522189 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 266461275, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } ```

Log 2

``` 0.001139 INFO Hello World! 0.274315 INFO waiting for clock... 0.274647 INFO clock ok 0.275703 INFO chip ID: 43439 0.281381 INFO loading fw 4.434783 INFO loading nvram 4.449483 INFO starting up core... 4.472990 INFO waiting for wifi init... 4.557550 INFO shared_addr 00016070 4.558859 INFO init done 4.559165 INFO Downloading CLM... 4.580552 DEBUG LOGS: hndarm_armr addr: 0x18003000, cr4_idx: 0 4.580684 DEBUG LOGS: 000000.001 4.580771 DEBUG LOGS: RTE (SDIO-CDC) 7.95.50 (fb3ea36 CY) on BCM43439 r5 @ 37.4/81.6/81.6MHz 4.580955 DEBUG LOGS: 000000.003 sdpcmdcdc0: Broadcom SDPCMD CDC driver 4.581107 DEBUG LOGS: 000000.007 reclaim section 0: Returned 45968 bytes to the heap 4.581272 DEBUG LOGS: 000000.011 wlc_bmac_info_init: host_enab 1 4.581422 DEBUG LOGS: 000000.037 wl0: wlc_ampdu_tx_set: AGG Mode = MAC+Ucode txmaxpkts 64 txmaxpkts_agg 0 4.581648 DEBUG LOGS: 000000.049 wl0: wlc_channels_commit: no valid channel for "#n" nbands 1 bandlocked 0 4.581874 DEBUG LOGS: 000000.053 wl0: Broadcom BCM43439 802.11 Wireless Controller 7.95.50 (fb3ea36 CY) 4.582073 DEBUG LOGS: 000000.056 TCAM: 256 used: 76 exceed:0 4.582205 DEBUG LOGS: 000000.058 reclaim section 1: Returned 86112 bytes to the heap 4.615999 WARN TX stalled 4.620673 WARN BCD event, incomplete header 4.624937 WARN BCD event, incomplete header 4.843303 INFO get clmload_status 4.881843 INFO Configuring misc stuff... 4.881905 INFO set bus:txglom = [00, 00, 00, 00] 4.920455 INFO set apsta = [01, 00, 00, 00] 4.959000 INFO get cur_etheraddr 4.997512 INFO mac addr: [28, cd, c1, 0b, 30, 67] 4.997586 INFO set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] 6.104426 DEBUG LOGS: 000001.016 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 6.104612 DEBUG LOGS: 000001.133 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 6.104793 DEBUG LOGS: 000001.138 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframe 6.222380 INFO set bus:txglom = [00, 00, 00, 00] 6.360997 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 6.499353 INFO set ampdu_mpdu = [04, 00, 00, 00] 6.637695 INFO set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] 6.829357 DEBUG LOGS: 000002.301 wl0: wl_open 7.110717 INFO INIT DONE 7.110767 INFO set pm2_sleep_ret = [c8, 00, 00, 00] 7.149096 INFO set bcn_li_bcn = [01, 00, 00, 00] 7.187638 INFO set bcn_li_dtim = [01, 00, 00, 00] 7.226110 INFO set assoc_listen = [0a, 00, 00, 00] 7.303423 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 7.304050 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3920894729, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 7.414336 INFO set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00] 7.452851 INFO set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff] 7.491381 INFO set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00] 11.238716 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [36, e, 13, 25, 7e, 4b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 11.243188 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [36, e, 13, 25, 7e, 4b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 11.243508 WARN JOIN failed with status=5 11.247720 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 0, 0, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] 11.268235 DEBUG LOGS: 000006.305 wlc_lcn20phy_rx_iq_cal_txrxgain_control: Too much or too little power? (gain_index=16) 11.268486 DEBUG LOGS: 000006.426 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 11.268667 DEBUG LOGS: 000006.543 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 11.268847 DEBUG LOGS: 000006.660 wl0: wlc_lcn20phy_rx_iq_est: IQ measurement timed out 11.269028 DEBUG LOGS: 000006.662 wl0: wlc_phy_do_dummy_tx: Waited 310 uS for ofdm txframe 11.269212 DEBUG LOGS: 000006.669 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for txcrs 11.269411 DEBUG LOGS: 000006.670 wl0: wlc_lcn20phy_idle_tssi_est, ERROR: idleTssi estPwr(OB): 0x002a Register avgTssi(OB, 7MSB): 0x0065 11.269676 DEBUG LOGS: 000006.746 wl0: JOIN: authentication failure, no ack 14.137117 DEBUG === EVENT ASSOC_REQ_IE: EventMessage { version: 2, flags: 0, event_type: 87, status: 0, reason: 0, auth_type: 0, datalen: 81, addr: [87, 4, 94, 9f, c6, 10], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [00, 0d, 54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c, 01, 08, 82, 84, 8b, 96, 24, 30, 48, 6c, 32, 04, 0c, 12, 18, 60, 21, 02, 05, 17, 24, 02, 01, 0e, 30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 0c, 00, dd, 09, 00, 10, 18, 02, 00, 00, 00, 00, 00, dd, 07, 00, 50, f2, 02, 00, 01, 00] 14.141722 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 0, reason: 0, auth_type: 0, datalen: 0, addr: [36, e, 13, 25, 7e, 4b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 14.162207 DEBUG LOGS: 000009.636 wl0: wlc_phy_do_dummy_tx: Waited 5010 uS for txcrs 14.221980 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [36, e, 13, 25, 7e, 4b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 14.226393 DEBUG === EVENT ASSOC: EventMessage { version: 2, flags: 0, event_type: 7, status: 5, reason: 0, auth_type: 0, datalen: 0, addr: [36, e, 13, 25, 7e, 4b], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 14.230873 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 1, reason: 0, auth_type: 0, datalen: 13, addr: [0, 0, 36, e, 13, 25], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 79, 6c, 65, 72, 27, 73, 20, 50, 69, 78, 65, 6c] 17.303280 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3614810059, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } ```

I noticed the weird typos, they look like bus corruption somewhere, I assumed over the serial debug link but it could be along the PIO path as you say. If these are all in places coming from the wifi chip then it seems likely.

No I've been meaning to try a different software stack to confirm the chip is working, I should definitely do that. I'll report back once I do.

Okay, I found the problem. I think I was underpowering the chip by only powering it with 3.3v (following the picoprobe instructions in the Getting started with Raspberry Pi Pico guide). I'm sure there are docs that say somewhere that you have to be connected to 5v power for the wifi chip to work, but that guide is for the Pico and not the Pico W. Oh well.

I was never able to get serial output with the SDK examples (with or without 5V power), so I wasn't able to verify if those worked. But I tried CircuitPython and it connected, and I'd seen some logs about power issues in the last round. Since CircuitPython was using USB I figured I'd try powering that port directly instead of powering off the probe's 3.3v. It worked!

Successful log

``` 0.001138 INFO Hello World! 0.274337 INFO waiting for clock... 0.274673 INFO clock ok 0.275735 INFO chip ID: 43439 0.281411 INFO loading fw 4.434919 INFO loading nvram 4.449610 INFO starting up core... 4.473085 INFO waiting for wifi init... 4.557797 INFO shared_addr 00016070 4.559108 INFO init done 4.559413 INFO Downloading CLM... 4.580815 DEBUG LOGS: hndarm_armr addr: 0x18003000, cr4_idx: 0 4.580944 DEBUG LOGS: 000000.001 4.581029 DEBUG LOGS: RTE (SDIO-CDC) 7.95.50 (fb3ea36 CY) on BCM43439 r5 @ 37.4/81.6/81.6MHz 4.581213 DEBUG LOGS: 000000.003 sdpcmdcdc0: Broadcom SDPCMD CDC driver 4.581365 DEBUG LOGS: 000000.007 reclaim section 0: Returned 45968 bytes to the heap 4.581531 DEBUG LOGS: 000000.011 wlc_bmac_info_init: host_enab 1 4.581680 DEBUG LOGS: 000000.037 wl0: wlc_ampdu_tx_set: AGG Mode = MAC+Ucode txmaxpkts 64 txmaxpkts_agg 0 4.581906 DEBUG LOGS: 000000.049 wl0: wlc_channels_commit: no valid channel for "#n" nbands 1 bandlocked 0 4.582133 DEBUG LOGS: 000000.053 wl0: Broadcom BCM43439 802.11 Wireless Controller 7.95.50 (fb3ea36 CY) 4.582332 DEBUG LOGS: 000000.056 TCAM: 256 used: 76 exceed:0 4.582463 DEBUG LOGS: 000000.058 reclaim section 1: Returned 86112 bytes to the heap 4.616263 WARN TX stalled 4.620989 WARN BCD event, incomplete data 4.625253 WARN BCD event, incomplete data 4.843603 INFO get clmload_status 4.882161 INFO Configuring misc stuff... 4.882225 INFO set bus:txglom = [00, 00, 00, 00] 4.920775 INFO set apsta = [01, 00, 00, 00] 4.959309 INFO get cur_etheraddr 4.997833 INFO mac addr: [28, cd, c1, 0b, 30, 67] 4.997905 INFO set country = [58, 58, 00, 00, ff, ff, ff, ff, 58, 58, 00, 00] 5.174505 INFO set bus:txglom = [00, 00, 00, 00] 5.313098 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 5.451458 INFO set ampdu_mpdu = [04, 00, 00, 00] 5.589812 INFO set bsscfg:event_msgs = [00, 00, 00, 00, ff, ff, f7, ff, ff, ee, bf, ff, 7f, ff, ff, ff, ff, ff, ff, ff, ff, fd, ff, ff, ff, ff, ff, ff] 5.781483 DEBUG LOGS: 000001.248 wl0: wl_open 6.062848 INFO INIT DONE 6.062896 INFO set pm2_sleep_ret = [c8, 00, 00, 00] 6.101202 INFO set bcn_li_bcn = [01, 00, 00, 00] 6.139749 INFO set bcn_li_dtim = [01, 00, 00, 00] 6.178221 INFO set assoc_listen = [0a, 00, 00, 00] 6.255513 INFO set ampdu_ba_wsize = [08, 00, 00, 00] 6.256150 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 3920894729, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 6.366411 INFO set bsscfg:sup_wpa = [00, 00, 00, 00, 01, 00, 00, 00] 6.404900 INFO set bsscfg:sup_wpa2_eapver = [00, 00, 00, 00, ff, ff, ff, ff] 6.443443 INFO set bsscfg:sup_wpa_tmo = [00, 00, 00, 00, c4, 09, 00, 00] 9.733065 DEBUG === EVENT ASSOC_REQ_IE: EventMessage { version: 2, flags: 0, event_type: 87, status: 0, reason: 0, auth_type: 0, datalen: 77, addr: [ce, 10, b0, 8d, 51, 75], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [00, 09, 54, 72, 65, 65, 68, 6f, 75, 73, 65, 01, 08, 82, 84, 8b, 96, 24, 30, 48, 6c, 32, 04, 0c, 12, 18, 60, 21, 02, 05, 17, 24, 02, 01, 0e, 30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 0c, 00, dd, 09, 00, 10, 18, 02, 00, 00, 00, 00, 00, dd, 07, 00, 50, f2, 02, 00, 01, 00] 9.737713 DEBUG === EVENT AUTH: EventMessage { version: 2, flags: 0, event_type: 3, status: 0, reason: 0, auth_type: 0, datalen: 0, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 9.742179 DEBUG === EVENT ASSOC_RESP_IE: EventMessage { version: 2, flags: 0, event_type: 88, status: 0, reason: 0, auth_type: 0, datalen: 102, addr: [60, 6c, 0, 0, 0, 0], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [01, 08, 82, 84, 8b, 96, 24, 30, 48, 6c, 32, 04, 0c, 12, 18, 60, 35, 01, 00, 41, 01, 00, 46, 05, 72, 08, 01, 00, 00, 7f, 08, 05, 00, 00, 00, 00, 00, 00, 40, dd, 18, 00, 50, f2, 04, 10, 4a, 00, 01, 10, 10, 3b, 00, 01, 03, 10, 49, 00, 06, 00, 37, 2a, 00, 01, 20, dd, 09, 00, 10, 18, 02, 02, 00, 8c, 00, 00, dd, 18, 00, 50, f2, 02, 01, 01, 84, 00, 03, a4, 00, 00, 27, a4, 00, 00, 42, 43, 5e, 00, 62, 32, 2f, 00] 9.746830 DEBUG === EVENT ASSOC: EventMessage { version: 2, flags: 0, event_type: 7, status: 0, reason: 0, auth_type: 0, datalen: 108, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [11, 14, 00, 00, 03, c0, 01, 08, 82, 84, 8b, 96, 24, 30, 48, 6c, 32, 04, 0c, 12, 18, 60, 35, 01, 00, 41, 01, 00, 46, 05, 72, 08, 01, 00, 00, 7f, 08, 05, 00, 00, 00, 00, 00, 00, 40, dd, 18, 00, 50, f2, 04, 10, 4a, 00, 01, 10, 10, 3b, 00, 01, 03, 10, 49, 00, 06, 00, 37, 2a, 00, 01, 20, dd, 09, 00, 10, 18, 02, 02, 00, 8c, 00, 00, dd, 18, 00, 50, f2, 02, 01, 01, 84, 00, 03, a4, 00, 00, 27, a4, 00, 00, 42, 43, 5e, 00, 62, 32, 2f, 00] 9.751487 DEBUG === EVENT LINK: EventMessage { version: 2, flags: 1, event_type: 16, status: 0, reason: 0, auth_type: 0, datalen: 22, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [30, 14, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 04, 01, 00, 00, 0f, ac, 02, 0c, 00] 9.771970 DEBUG LOGS: 000005.237 wl0: link up (wl0) 9.776654 DEBUG === EVENT JOIN: EventMessage { version: 2, flags: 0, event_type: 1, status: 0, reason: 0, auth_type: 0, datalen: 0, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 9.776904 INFO JOINED 9.777209 INFO set gpioout = [01, 00, 00, 00, 00, 00, 00, 00] 9.777670 INFO link_up = true 9.777720 DEBUG Lost IP configuration 9.781172 DEBUG === EVENT SET_SSID: EventMessage { version: 2, flags: 0, event_type: 0, status: 0, reason: 0, auth_type: 0, datalen: 9, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [54, 72, 65, 65, 68, 6f, 75, 73, 65] 9.785646 DEBUG === EVENT PSK_SUP: EventMessage { version: 2, flags: 0, event_type: 46, status: 6, reason: 0, auth_type: 0, datalen: 0, addr: [81, a, 12, 82, d8, 93], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 9.824578 INFO Listening on TCP:1234... 9.998114 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 16.255170 DEBUG DHCP send DISCOVER to 255.255.255.255: Repr { message_type: Discover, transaction_id: 1941686750, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: None, parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 19.498585 DEBUG DHCP recv Offer from 192.168.1.1: Repr { message_type: Offer, transaction_id: 1941686750, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 192.168.1.178, server_ip: 192.168.1.1, router: Some(192.168.1.1), subnet_mask: Some(255.255.255.0), relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: None, server_identifier: Some(192.168.1.1), parameter_request_list: None, dns_servers: Some([192.168.1.1]), max_size: None, lease_duration: Some(86400), renew_duration: Some(43200), rebind_duration: Some(75600), additional_options: [] } 19.499146 DEBUG DHCP send request to 255.255.255.255: Repr { message_type: Request, transaction_id: 506306819, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 0.0.0.0, server_ip: 0.0.0.0, router: None, subnet_mask: None, relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: Some(192.168.1.178), client_identifier: Some(Address([40, 205, 193, 11, 48, 103])), server_identifier: Some(192.168.1.1), parameter_request_list: Some([1, 3, 6]), dns_servers: None, max_size: Some(1432), lease_duration: None, renew_duration: None, rebind_duration: None, additional_options: [] } 19.541395 DEBUG DHCP recv Ack from 192.168.1.1: Repr { message_type: Ack, transaction_id: 506306819, secs: 0, client_hardware_address: Address([40, 205, 193, 11, 48, 103]), client_ip: 0.0.0.0, your_ip: 192.168.1.178, server_ip: 192.168.1.1, router: Some(192.168.1.1), subnet_mask: Some(255.255.255.0), relay_agent_ip: 0.0.0.0, broadcast: false, requested_ip: None, client_identifier: None, server_identifier: Some(192.168.1.1), parameter_request_list: None, dns_servers: Some([192.168.1.1]), max_size: None, lease_duration: Some(86400), renew_duration: Some(43200), rebind_duration: Some(75600), additional_options: [] } 19.542149 DEBUG Acquired IP configuration: 19.542178 DEBUG IP address: 192.168.1.178/24 19.542270 DEBUG Default gateway: 192.168.1.1 19.542335 DEBUG DNS server 0: 192.168.1.1 31.546245 INFO Received connection from Some(192.168.1.37:58943) 31.546430 INFO set gpioout = [01, 00, 00, 00, 01, 00, 00, 00] 34.851160 INFO rxd hello 44.892221 DEBUG timeout exceeded 44.893433 WARN read error: ConnectionReset 44.893653 INFO set gpioout = [01, 00, 00, 00, 00, 00, 00, 00] 44.965266 INFO Listening on TCP:1234... 49.639649 INFO Received connection from Some(192.168.1.37:58955) 49.639829 INFO set gpioout = [01, 00, 00, 00, 01, 00, 00, 00] 53.898323 DEBUG === EVENT TXFAIL: EventMessage { version: 2, flags: 0, event_type: 20, status: 2, reason: 0, auth_type: 0, datalen: 0, addr: [e0, 3f, 49, e2, a6, c8], ifname: [77, 6c, 30, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], ifidx: 0, bsscfgidx: 0, } [] 53.994631 INFO rxd is anyone there? 60.041790 INFO rxd omg it's working 62.805922 INFO rxd yay 72.846233 DEBUG timeout exceeded 72.847419 WARN read error: ConnectionReset 72.847626 INFO set gpioout = [01, 00, 00, 00, 00, 00, 00, 00] 72.919282 INFO Listening on TCP:1234... ```

The above log is on the slow-pio branch, but the behavior seems to be the same on master. There seems to be some timeout resetting the connection each time. But in any case, it mostly works.

Thanks for your help!

embassy-rs / cyw43

Failing to connect (Pico W) #75