Crash with ESWIFI ( b_l4s5i_iot01a board) when enabling DHCPV4

[davidalo]

Describe the bug

Using b_l4s5i_iot01a I have a crash if I enable DHCPV4. I have been reading some threads about socket offloading which may be related but I couldn't find a similar Bug Report for this.

Using Zephyr 3.7.0.

If I run samples/net/wifi/ there is no problem, but as soon as I enable DHCPV4 client using CONFIG_NET_CONFIG_SETTINGS=y it crashes:

*** Booting Zephyr OS build v3.7.0 ***
[00:00:00.534,000] <inf> net_config: Initializing network
[00:00:00.534,000] <inf> net_config: Running dhcpv4 client...
uart:~$ 
[00:00:07.534,000] <err> os: ***** USAGE FAULT *****
[00:00:07.534,000] <err> os:   Illegal use of the EPSR
[00:00:07.534,000] <err> os: r0/a1:  0x20000630  r1/a2:  0x200081b0  r2/a3:  0x200035b4
[00:00:07.534,000] <err> os: r3/a4:  0x00000000 r12/ip:  0x00000010 r14/lr:  0x0800ce01
[00:00:07.534,000] <err> os:  xpsr:  0x40000000
[00:00:07.534,000] <err> os: Faulting instruction address (r15/pc): 0x00000000
[00:00:07.534,000] <err> os: >>> ZEPHYR FATAL ERROR 35: Unknown error on CPU 0
[00:00:07.534,000] <err> os: Current thread: 0x20002538 (sysworkq)
[00:00:07.614,000] <err> os: Halting system

After some debugging it seems that a null reference is being used in DHCP code.

To Reproduce

Expected behavior

Impact

Logs and console output

Environment (please complete the following information):

• OS: (e.g. Linux, MacOS, Windows)
• Toolchain (e.g Zephyr SDK, ...)
• Commit SHA or Version used

Additional context

[github-actions]

Hi @davidalo! We appreciate you submitting your first issue for our open-source project. 🌟

Even though I'm a bot, I can assure you that the whole community is genuinely grateful for your time and effort. 🤖💙

[jukkar]

There is a crash bug when enabling both the DHCPv4 and v4-to-v6-mapping options, this is fixed by #76357 in 3.7.1 (not yet released). So just wanted to make sure if you have the config options set as described in issue #76360

[davidalo]

@jukkar I'm not explicitly enabling CONFIG_NET_IPV4_MAPPING_TO_IPV6. In fact, I have IPV6 completely disabled.

Here you have all my CONFIG_NET_ configurations:

CONFIG_NET_LOG=y
CONFIG_NETWORKING=y
CONFIG_TEST_RANDOM_GENERATOR=y
CONFIG_NET_IPV6=n
# CONFIG_NET_IF_UNICAST_IPV6_ADDR_COUNT=3
# CONFIG_NET_IF_MCAST_IPV6_ADDR_COUNT=2
CONFIG_NET_IPV4=y
CONFIG_NET_IF_UNICAST_IPV4_ADDR_COUNT=3
CONFIG_NET_IF_MCAST_IPV4_ADDR_COUNT=2
CONFIG_NET_PKT_RX_COUNT=10
CONFIG_NET_PKT_TX_COUNT=10
CONFIG_NET_BUF_RX_COUNT=10
CONFIG_NET_BUF_TX_COUNT=10
CONFIG_NET_MAX_CONTEXTS=5
CONFIG_NET_CONFIG_NEED_IPV6=n
CONFIG_NET_CONFIG_NEED_IPV4=y
CONFIG_NET_CONFIG_SETTINGS=y

CONFIG_NET_MGMT=y
CONFIG_NET_MGMT_EVENT=y
CONFIG_NET_CONNECTION_MANAGER=y
CONFIG_NET_CONNECTION_MANAGER_LOG_LEVEL_DBG=y
CONFIG_NET_SHELL=y
CONFIG_NET_LOG=y

CONFIG_NET_LOG=y
CONFIG_INIT_STACKS=y
CONFIG_NET_STATISTICS=y
CONFIG_WIFI=y
CONFIG_WIFI_LOG_LEVEL_INF=y
CONFIG_NET_L2_WIFI_MGMT_LOG_LEVEL_DBG=y
CONFIG_NET_L2_WIFI_MGMT=y
CONFIG_NET_L2_WIFI_SHELL=y

# eswifi dhcpv4 does not work with offloaded sockets
CONFIG_WIFI_ESWIFI=y
CONFIG_NET_DHCPV4=y 
CONFIG_NET_DHCPV4_LOG_LEVEL_DBG=y

I will try later today to explicitly disable mapping by adding CONFIG_NET_IPV4_MAPPING_TO_IPV6=n and let you know.

[jukkar]

If you disable IPv6, then the mapping option is disabled too, so your issue is different.

[davidalo]

Happy to share backtrace from GDB or any other information if useful.

[jukkar]

Backtrace would be helpful to see

[davidalo]

@jukkar

Logs:

[00:00:00.635,000] <inf> net_config: Running dhcpv4 client...
[00:00:00.635,000] <dbg> conn_mgr: conn_mgr_ipv4_events_handler: (net_mgmt): IPv4 event 0xe0040007 received on iface 1 (0x20000980)
[00:00:00.635,000] <dbg> conn_mgr: conn_mgr_ipv4_events_handler: (net_mgmt): Iface index 0
[00:00:00.635,000] <dbg> net_dhcpv4: dhcpv4_start_internal: (main): iface 0x20000980 state=init
[00:00:00.635,000] <dbg> net_dhcpv4: dhcpv4_start_internal: (main): wait timeout=4s
[00:00:00.635,000] <dbg> net_dhcpv4: dhcpv4_set_timeout: (main): sched timeout dhcpv4=0x200009f0 timeout=4s
[00:00:00.635,000] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20000980 dhcpv4=0x200009f0 state=init timeleft=4
[00:00:00.635,000] <dbg> net_dhcpv4: dhcpv4_timeout: (sysworkq): Waiting for 4s
[00:00:04.636,000] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20000980 dhcpv4=0x200009f0 state=init timeleft=0
[00:00:04.636,000] <dbg> net_dhcpv4: dhcpv4_enter_selecting: (sysworkq): enter state=selecting
[00:00:04.636,000] <err> os: ***** USAGE FAULT *****
[00:00:04.636,000] <err> os:   Illegal use of the EPSR
[00:00:04.636,000] <err> os: r0/a1:  0x20000980  r1/a2:  0x2000c298  r2/a3:  0x20007440
[00:00:04.636,000] <err> os: r3/a4:  0x00000000 r12/ip:  0x00000010 r14/lr:  0x0800f995
[00:00:04.636,000] <err> os:  xpsr:  0x40000000
[00:00:04.636,000] <err> os: Faulting instruction address (r15/pc): 0x00000000
[00:00:04.636,000] <err> os: >>> ZEPHYR FATAL ERROR 35: Unknown error on CPU 0
[00:00:04.636,000] <err> os: Current thread: 0x20003458 (sysworkq)
[00:00:04.742,000] <err> os: Halting system

Backtrace 1:

  0x08007358 in z_arm_usage_fault () at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/arch/arm/core/cortex_m/fault_s.S:102
#6  <signal handler called>
#7  0x00000000 in ?? ()
#8  0x0800f994 in net_if_tx (iface=0x20000980 <__net_if_dts_ord_126_0>, pkt=pkt@entry=0x2000c298 <_k_mem_slab_buf_tx_pkts>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/ip/net_if.c:262
#9  0x0802c1e6 in net_if_queue_tx (iface=iface@entry=0x20000980 <__net_if_dts_ord_126_0>, pkt=pkt@entry=0x2000c298 <_k_mem_slab_buf_tx_pkts>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/ip/net_if.c:360
#10 0x0800fade in net_if_send_data (iface=0x20000980 <__net_if_dts_ord_126_0>, pkt=pkt@entry=0x2000c298 <_k_mem_slab_buf_tx_pkts>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/ip/net_if.c:528
#11 0x0800f048 in net_send_data (pkt=pkt@entry=0x2000c298 <_k_mem_slab_buf_tx_pkts>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/include/zephyr/net/net_pkt.h:340
#12 0x0801c594 in dhcpv4_send_discover (iface=iface@entry=0x20000980 <__net_if_dts_ord_126_0>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/lib/dhcpv4/dhcpv4.c:638
#13 0x0801d790 in dhcpv4_manage_timers (now=4636, iface=0x20000980 <__net_if_dts_ord_126_0>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/lib/dhcpv4/dhcpv4.c:805
#14 dhcpv4_timeout (work=<optimized out>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/lib/dhcpv4/dhcpv4.c:869
#15 0x08025960 in work_queue_main (workq_ptr=0x20003458 <k_sys_work_q>, p2=<optimized out>, p3=<optimized out>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/kernel/work.c:688
#16 0x0800385e in z_thread_entry (entry=0x80258dd <work_queue_main>, p1=0x20003458 <k_sys_work_q>, p2=0x0, p3=0x0) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/lib/os/thread_entry.c:48

Backtrace 2:

Breakpoint 1, net_if_tx (iface=0x20000980 <__net_if_dts_ord_126_0>, pkt=pkt@entry=0x2000c298 <_k_mem_slab_buf_tx_pkts>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/subsys/net/ip/net_if.c:214
214             struct net_linkaddr ll_dst = {
(gdb) n
Info : halted: PC: 0x0800f920
halted: PC: 0x0800f920
Info : halted: PC: 0x0800f922
halted: PC: 0x0800f922
Info : halted: PC: 0x0800f924
halted: PC: 0x0800f924
Info : halted: PC: 0x0800f926
halted: PC: 0x0800f926
Info : halted: PC: 0x0800f92a
halted: PC: 0x0800f92a
225             if (!pkt) {
(gdb) n
Info : halted: PC: 0x0800f92c
halted: PC: 0x0800f92c
Info : halted: PC: 0x0800f92e
halted: PC: 0x0800f92e
Info : halted: PC: 0x0800f930
halted: PC: 0x0800f930
Info : halted: PC: 0x0800f932
halted: PC: 0x0800f932
237             if (!sys_slist_is_empty(&link_callbacks)) {
(gdb) n
Info : halted: PC: 0x0800f934
halted: PC: 0x0800f934
Info : halted: PC: 0x0800f936
halted: PC: 0x0800f936
Info : halted: PC: 0x0800f95c
halted: PC: 0x0800f95c
329             return pkt->context;
(gdb) n
Info : halted: PC: 0x0800f95e
halted: PC: 0x0800f95e
Info : halted: PC: 0x0800f960
halted: PC: 0x0800f960
247             context = net_pkt_context(pkt);
(gdb) n
Info : halted: PC: 0x0800f964
halted: PC: 0x0800f964
249             if (net_if_flag_is_set(iface, NET_IF_LOWER_UP)) {
(gdb) n
Info : halted: PC: 0x0802be9e
halted: PC: 0x0802be9e
Info : halted: PC: 0x0800f96a
halted: PC: 0x0800f96a
Info : halted: PC: 0x0800f96c
halted: PC: 0x0800f96c
261                     net_if_tx_lock(iface);
(gdb) n
Info : halted: PC: 0x0800f96e
halted: PC: 0x0800f96e
Info : halted: PC: 0x0800f970
halted: PC: 0x0800f970
Info : halted: PC: 0x0802be9e
halted: PC: 0x0802be9e
Info : halted: PC: 0x0800f976
halted: PC: 0x0800f976
Info : halted: PC: 0x0800f97a
halted: PC: 0x0800f97a
Info : halted: PC: 0x0800f97e
halted: PC: 0x0800f97e
Info : halted: PC: 0x0800f982
halted: PC: 0x0800f982
Info : halted: PC: 0x0802be8c
halted: PC: 0x0802be8c
262                     status = net_if_l2(iface)->send(iface, pkt);
(gdb) s
Info : halted: PC: 0x0800f988
halted: PC: 0x0800f988
Info : halted: PC: 0x0802be30
halted: PC: 0x0802be30
net_if_l2 (iface=iface@entry=0x20000980 <__net_if_dts_ord_126_0>) at /home/david/devel/davidalo/zephyr-remote-controller/zephyr/include/zephyr/net/net_if.h:902
902             if (!iface || !iface->if_dev) {
(gdb) n
Info : halted: PC: 0x0802be32
halted: PC: 0x0802be32
Info : halted: PC: 0x0802be34
halted: PC: 0x0802be34
Info : halted: PC: 0x0802be36
halted: PC: 0x0802be36
906             return iface->if_dev->l2;
(gdb) p *iface
$7 = {if_dev = 0x20000a70 <__net_if_dev_dts_ord_126_0>, stats = {processing_error = 0, bytes = {sent = 0, received = 0}, ip_errors = {vhlerr = 0, hblenerr = 0, lblenerr = 0, fragerr = 0, chkerr = 0, protoerr = 0}, ipv4 = {recv = 0, 
      sent = 0, forwarded = 0, drop = 0}, icmp = {recv = 0, sent = 0, drop = 0, typeerr = 0, chkerr = 0}, udp = {drop = 0, recv = 0, sent = 0, chkerr = 0}, ipv4_igmp = {recv = 0, sent = 0, drop = 0}}, config = {ip = {
      ipv4 = 0x20003d94 <ipv4_addresses>}, dhcpv4 = {node = {next = 0x0}, timer_start = 635, request_time = 3, xid = 2540158266, lease_time = 0, renewal_time = 0, rebinding_time = 0, server_id = {{s4_addr = "\000\000\000", 
          s4_addr16 = {0, 0}, s4_addr32 = {0}, s_addr = 0}}, requested_ip = {{s4_addr = "\000\000\000", s4_addr16 = {0, 0}, s4_addr32 = {0}, s_addr = 0}}, netmask = {{s4_addr = "\000\000\000", s4_addr16 = {0, 0}, s4_addr32 = {0}, 
          s_addr = 0}}, state = NET_DHCPV4_SELECTING, attempts = 0 '\000', request_server_addr = {{s4_addr = "\000\000\000", s4_addr16 = {0, 0}, s4_addr32 = {0}, s_addr = 0}}, response_src_addr = {{s4_addr = "\000\000\000", 
          s4_addr16 = {0, 0}, s4_addr32 = {0}, s_addr = 0}}}, name = "wlan0\000\000\000"}, lock = {wait_q = {waitq = {{head = 0x20000a40 <__net_if_dts_ord_126_0+192>, next = 0x20000a40 <__net_if_dts_ord_126_0+192>}, {
          tail = 0x20000a40 <__net_if_dts_ord_126_0+192>, prev = 0x20000a40 <__net_if_dts_ord_126_0+192>}}}, owner = 0x0, lock_count = 0, owner_orig_prio = -1}, tx_lock = {wait_q = {waitq = {{
          head = 0x20000a54 <__net_if_dts_ord_126_0+212>, next = 0x20000a54 <__net_if_dts_ord_126_0+212>}, {tail = 0x20000a54 <__net_if_dts_ord_126_0+212>, prev = 0x20000a54 <__net_if_dts_ord_126_0+212>}}}, 
    owner = 0x20003458 <k_sys_work_q>, lock_count = 1, owner_orig_prio = -1}, pe_enabled = 0 '\000', pe_prefer_public = 0 '\000', _unused = 0 '\000'}
(gdb) p *(iface->if_dev)
$8 = {dev = 0x8032d00 <__device_dts_ord_126>, l2 = 0x20000a98 <_net_l2_OFFLOADED_NETDEV>, l2_data = 0x0, flags = {833}, link_addr = {addr = 0x2000243e <eswifi0+406> "\304\177Q\221CK\r\n[SOMA][EOMA]", len = 6 '\006', type = 3 '\003'}, 
  offload = 0x20000404 <eswifi_offload>, mtu = 1500, socket_offload = 0x8023f29 <eswifi_socket_create>, oper_state = NET_IF_OPER_UP}
(gdb) p *(iface->if_dev->l2)
$9 = {recv = 0x0, send = 0x0, enable = 0x802bb7b <offloaded_netdev_if_enable>, get_flags = 0x0}

In backtrace 2 you can see that send is null (because it is an offloaded interface) and it's being called, that's why it's crashing.

[davidalo]

After doing some debugging, it seems that DHCPV4 is crashing when using offloaded interfaces. Initially, I thought that IP/DHCP was handled by Zephyr instead of ESWIFI module but now I realized that it's handled by the chip.

However, this should not lead to a crash, it should fail at compile time or at runtime without crashing.

[jukkar]

Thanks for the analysis, this should be fixed by #76348, and in v3.7.1 by #76716

[jukkar]

BTW, you probably should not enable CONFIG_NET_DHCPV4 because you are using offloaded implementation.

[mmahadevan108]

Thanks for the analysis, this should be fixed by #76348, and in v3.7.1 by #76716

@davidalo, can you give it a try on the latest Zephyr main