Ethernet and BLE Mesh Conflicting

[wwilkins21]

Describe the bug
I've been able to get BLE Mesh project and Ethernet project working separately but was failing to integrate them together.
So I decided to start slowly adding configs over to my working Ethernet project. Using CONFIG_BT as a prerequisite to CONFIG_BT_MESH, when I add just this configuration to my prj.conf is when the issue below happens.

DHCP Fails to initialize and start up Ethernet interface when CONFIG_BT=y is enabled.
I have a duplicate ticket opened in devzone ticket, which they recommended I come ask over here.

To Reproduce
Steps to reproduce the behavior:
Simple ethernet sample:

.overlay

&spi4 {
    w5500: w5500@0 {
        compatible = "wiznet,w5500";
        reg = <0>;
        spi-max-frequency = <10000000>;
        zephyr,random-mac-address;
        int-gpios = <&gpio0 7 GPIO_ACTIVE_LOW>;
        reset-gpios = <&gpio1 5 GPIO_ACTIVE_LOW>;
    };
};

.conf

# === Ethernet
CONFIG_NETWORKING=y
CONFIG_NET_IPV4=y
CONFIG_NET_IPV6=n
CONFIG_NET_DHCPV4=y
CONFIG_NET_LOG=y
CONFIG_NET_SHELL=y
CONFIG_NET_STATISTICS=y
CONFIG_DNS_RESOLVER=y
CONFIG_NET_L2_ETHERNET=y
CONFIG_ETHERNET_LOG_LEVEL_DBG=y
CONFIG_NET_L2_ETHERNET_LOG_LEVEL_DBG=y
CONFIG_NET_DHCPV4_LOG_LEVEL_DBG=y
CONFIG_NET_L2_ETHERNET_MGMT=y
CONFIG_ETH_W5500=y
CONFIG_ETH_W5500_TIMEOUT=1000
CONFIG_NET_MGMT=y

main

    struct net_if *iface;
    iface = net_if_get_default();
    if (iface == NULL) {
        printk("Error getting default network interface.\n");
        return;
    }

    // Link status callback handler
    net_mgmt_init_event_callback(&cb, net_mgmt_handler, NET_EVENT_ETHERNET_CARRIER_ON | NET_EVENT_ETHERNET_CARRIER_OFF);
    net_mgmt_add_event_callback(&cb);

    // Start DHCP
    net_dhcpv4_start(iface);

Then once you get a working Ethernet sample add the config

CONFIG_BT=y

To the .conf file, and DHCP will begin failing to initialize the Ethernet interface.

Expected behavior
Ethernet and Bluetooth/BLE Mesh coexist together.

Impact
Showstopper

Logs and console output
Output:

[00:00:04.443,389] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20002228 dhcpv4=0x20002298 state=init timeleft=0
uart:~$ net iface

Interface eth0 (0x20002228) (Ethernet) [1]
================================
Interface is down.
uart:~$ net iface up 1
Cannot take interface 1 up (-120)

Environment (please complete the following information):
Setup:
HW: Fanstel-WT02C40C (nrf5340/7002), WIZ5500 Ethernet Module

Additional context
I've tried increasing all possible connections with
CONFIG_NET_IF_MAX_IPV4_COUNT=2
CONFIG_NET_IF_UNICAST_IPV4_ADDR_COUNT=2

But can't find any such coexistence API's for Eth and BLE.

[github-actions]

Hi @wwilkins21! 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. 🤖💙

[rlubos]

DHCP Fails to initialize and start up Ethernet interface

To clarify, DHCP does not start up Ethernet interface in any way, the interface needs to be already up for DHCP to work (the only interaction with the network interface is assigning IP address to it). The interface should've been brought up on boot, unless you configured it otherwise explicitly.

But anyway, I can't really think of any direct relationship between enabling CONFIG_BT and ethernet interfaces. It is suspicious though that net iface up 1, it reports '`EALREADY, which implies it was already brought up (likely on boot), but did not reach operational up state. For ethernet, it could only happen if the carrier state of the interface remains OFF (cable plugged out), which suggests broken cable detection in the driver.

Maybe try to enable CONFIG_NET_IF_LOG_LEVEL_DBG to see what state transitions happen on the interface.

[jukkar]

The carrier detection PR #68752 for this driver was merged in Feb so it should be able to detect the cable status.
@wwilkins21 do you see Ethernet carrier on/off events you are monitoring in your application?

[wwilkins21]

@rlubos

Yeah sorry I should have been more specific. The logs aren't very verbose even at dbg

[00:00:00.613,800] <inf> eth_w5500: W5500 Initialized
[00:00:00.614,105] <dbg> net_if: net_if_init: (main):
[00:00:00.614,135] <dbg> net_if: init_iface: (main): On iface 0x20001f90
[00:00:00.614,166] <dbg> net_ethernet: ethernet_init: (main): Initializing Ethernet L2 0x20006754 for iface 0x20001f90
[00:00:00.614,288] <dbg> net_if: update_operational_state: (main): iface 0x20001f90, oper state DOWN admin DOWN carrier OFF dormant OFF
[00:00:00.614,532] <dbg> net_if: net_if_post_init: (main):
[00:00:00.614,562] <dbg> net_if: net_if_up: (main): iface 0x20001f90
[00:00:00.614,990] <dbg> net_if: net_if_ipv4_maddr_add: (main): interface 0x20001f90 address 224.0.0.1 added
[00:00:00.615,112] <dbg> net_if: update_operational_state: (main): iface 0x20001f90, oper state DOWN admin UP carrier OFF dormant OFF
[00:00:00.615,142] <dbg> net_dhcpv4: net_dhcpv4_init: (main):
IFace: eth0
[00:00:02.616,241] <dbg> net_dhcpv4: dhcpv4_start_internal: (eth_tid): iface 0x20001f90 state=init
[00:00:02.616,302] <dbg> net_dhcpv4: dhcpv4_start_internal: (eth_tid): wait timeout=9s
[00:00:02.616,333] <dbg> net_dhcpv4: dhcpv4_set_timeout: (eth_tid): sched timeout dhcvp4=0x20002000 timeout=9s
DHCP started
Waiting for DHCP address...
[00:00:02.616,455] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20001f90 dhcpv4=0x20002000 state=init timeleft=9
[00:00:02.616,485] <dbg> net_dhcpv4: dhcpv4_timeout: (sysworkq): Waiting for 9s
Power-on-reset
[00:00:11.616,668] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20001f90 dhcpv4=0x20002000 state=init timeleft=0

@jukkar Yeah I've used that commit, just on my working Ethernet sample using what I provided above, I can detect the link status. Once I include CONFIG_BT is when the interface is never brought up

[wwilkins21]

Same code without CONFIG_BT

[00:00:00.263,061] <inf> eth_w5500: W5500 Initialized
[00:00:00.263,336] <dbg> net_if: net_if_init: (main):
[00:00:00.263,366] <dbg> net_if: init_iface: (main): On iface 0x20001380
[00:00:00.263,397] <dbg> net_ethernet: ethernet_init: (main): Initializing Ethernet L2 0x200044cc for iface 0x20001380
[00:00:00.263,549] <dbg> net_if: update_operational_state: (main): iface 0x20001380, oper state DOWN admin DOWN carrier OFF dormant OFF
[00:00:00.263,763] <dbg> net_if: net_if_post_init: (main):
[00:00:00.263,793] <dbg> net_if: net_if_up: (main): iface 0x20001380
[00:00:00.264,251] <dbg> net_if: net_if_ipv4_maddr_add: (main): interface 0x20001380 address 224.0.0.1 added
[00:00:00.264,373] <dbg> net_if: update_operational_state: (main): iface 0x20001380, oper state DOWN admin UP carrier OFF dormant OFF
[00:00:00.264,373] <dbg> net_dhcpv4: net_dhcpv4_init: (main):
*** Booting nRF Connect SDK v3.5.99-ncs1-2-gc70cce21ffa4 ***
[00:00:02.263,610] <inf> eth_w5500: w5500@0: Link up
[00:00:02.263,671] <dbg> net_ethernet: carrier_on_off: (sysworkq): Carrier ON for interface 0x20001380
[00:00:02.263,793] <dbg> net_if: update_operational_state: (sysworkq): iface 0x20001380, oper state UP admin UP carrier ON dormant OFF
IFace: eth0[00:00:02.367,706] <dbg> net_dhcpv4: dhcpv4_start_internal: (eth_tid): iface 0x20001380 state=init
[00:00:02.367,889] <dbg> net_dhcpv4: dhcpv4_start_internal: (eth_tid): wait timeout=5s
[00:00:02.367,889] <dbg> net_dhcpv4: dhcpv4_set_timeout: (eth_tid): sched timeout dhcvp4=0x200013f0 timeout=5s
DHCP started
Waiting for DHCP address...
[00:00:02.368,011] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20001380 dhcpv4=0x200013f0 state=init timeleft=5
[00:00:02.368,041] <dbg> net_dhcpv4: dhcpv4_timeout: (sysworkq): Waiting for 5s
Reset by pin-reset
[00:00:02.430,175] <dbg> eth_w5500: w5500_thread: IR received
[00:00:02.431,457] <dbg> net_ethernet: ethernet_recv: (rx_q[0]): iface 0x20001380 src 60:3E:5F:8C:02:DA dst 01:00:5E:00:00:FB type 0x800 len 359
[00:00:02.431,579] <dbg> eth_w5500: w5500_thread: RX Done
[00:00:02.431,732] <dbg> eth_w5500: w5500_thread: IR received
.....Alot of ARPS
[00:00:07.237,091] <dbg> net_ethernet: ethernet_recv: (rx_q[0]): iface 0x20001380 src 70:85:C2:3D:21:4F dst FF:FF:FF:FF:FF:FF type 0x806 len 60
[00:00:07.237,152] <dbg> net_ethernet: ethernet_recv: (rx_q[0]): ARP packet from 70:85:C2:3D:21:4F received
[00:00:07.237,182] <dbg> eth_w5500: w5500_thread: RX Done
[00:00:07.368,133] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20001380 dhcpv4=0x200013f0 state=init timeleft=0
[00:00:07.368,194] <dbg> net_dhcpv4: dhcpv4_enter_selecting: (sysworkq): enter state=selecting
[00:00:07.368,408] <dbg> net_if: net_if_tx: (sysworkq): Processing (pkt 0x200258f8, prio 1) network packet iface 0x20001380/1
[00:00:07.368,499] <dbg> net_ethernet: ethernet_fill_header: (sysworkq): iface 0x20001380 src 02:08:DC:AA:9B:7C dst FF:FF:FF:FF:FF:FF type 0x800 len 14
[00:00:07.369,445] <dbg> net_dhcpv4: dhcpv4_set_timeout: (sysworkq): sched timeout dhcvp4=0x200013f0 timeout=5s
[00:00:07.369,476] <dbg> net_dhcpv4: dhcpv4_send_discover: (sysworkq): send discover xid=0x5f045b8b timeout=5s
[00:00:07.369,506] <dbg> net_dhcpv4: dhcpv4_timeout: (sysworkq): Waiting for 5s
[00:00:07.369,689] <dbg> eth_w5500: w5500_thread: IR received
[00:00:07.369,720] <dbg> eth_w5500: w5500_thread: TX Done
[00:00:07.369,781] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20001380 dhcpv4=0x200013f0 state=selecting timeleft=5
[00:00:07.369,812] <dbg> net_dhcpv4: dhcpv4_timeout: (sysworkq): Waiting for 5s
[00:00:07.371,307] <dbg> eth_w5500: w5500_thread: IR received
[00:00:07.372,039] <dbg> eth_w5500: w5500_thread: RX Done
[00:00:07.372,161] <dbg> net_ethernet: ethernet_recv: (rx_q[0]): iface 0x20001380 src E8:6F:F2:D1:BC:70 dst FF:FF:FF:FF:FF:FF type 0x806 len 60
[00:00:07.372,192] <dbg> net_ethernet: ethernet_recv: (rx_q[0]): ARP packet from E8:6F:F2:D1:BC:70 received
.....More ARPS
[00:00:08.734,313] <dbg> eth_w5500: w5500_thread: RX Done
[00:00:08.760,894] <dbg> eth_w5500: w5500_thread: IR received
[00:00:08.761,657] <dbg> net_ethernet: ethernet_recv: (rx_q[0]): iface 0x20001380 src 40:1A:58:C2:21:AF dst FF:FF:FF:FF:FF:FF type 0x800 len 74
[00:00:08.761,779] <dbg> eth_w5500: w5500_thread: RX Done
[00:00:09.311,126] <dbg> net_dhcpv4: net_dhcpv4_input: (rx_q[0]):   ciaddr=0.0.0.0
[00:00:09.311,157] <dbg> net_dhcpv4: net_dhcpv4_input: (rx_q[0]):   yiaddr=192.168.0.51
[00:00:09.311,187] <dbg> net_dhcpv4: net_dhcpv4_input: (rx_q[0]):   siaddr=0.0.0.0
[00:00:09.311,187] <dbg> net_dhcpv4: net_dhcpv4_input: (rx_q[0]):   giaddr=0.0.0.0]
[00:00:09.311,309] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_server_id: 192.168.0.1
[00:00:09.311,340] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_lease_time: 86400
[00:00:09.311,401] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_subnet_mask 255.255.255.0
[00:00:09.311,492] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_router: 192.168.0.1
[00:00:09.311,706] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): option unknown: 15
[00:00:09.319,274] <dbg> net_dhcpv4: net_dhcpv4_input: (rx_q[0]):   siaddr=0.0.0.0
[00:00:09.319,305] <dbg> net_dhcpv4: net_dhcpv4_input: (rx_q[0]):   giaddr=0.0.0.0]
[00:00:09.319,396] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_server_id: 192.168.0.1
[00:00:09.319,458] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_lease_time: 86400
[00:00:09.319,519] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_subnet_mask 255.255.255.0
[00:00:09.319,610] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_router: 192.168.0.1
[00:00:09.319,671] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): option unknown: 15
[00:00:09.319,702] <dbg> net_dhcpv4: dhcpv4_parse_options: (rx_q[0]): options_end
[00:00:09.319,763] <dbg> net_dhcpv4: dhcpv4_handle_reply: (rx_q[0]): state=requesting msg=ack
[00:00:09.319,793] <inf> net_dhcpv4: Received: 192.168.0.51
[00:00:09.319,885] <dbg> net_if: net_if_ipv4_addr_add: (rx_q[0]): [0] interface 0x20001380 address 192.168.0.51 type DHCP added
[00:00:09.319,915] <dbg> net_dhcpv4: dhcpv4_enter_bound: (rx_q[0]): enter state=bound renewal=43200s rebinding=75600s
[00:00:09.319,946] <dbg> net_dhcpv4: dhcpv4_set_timeout: (rx_q[0]): sched timeout dhcvp4=0x200013f0 timeout=43200s
[00:00:09.320,068] <dbg> net_dhcpv4: dhcpv4_manage_timers: (sysworkq): iface 0x20001380 dhcpv4=0x200013f0 state=bound timeleft=43200
[00:00:09.320,098] <dbg> net_dhcpv4: dhcpv4_timeout: (sysworkq): Waiting for 43200s

[rlubos]

I still don't see how CONFIG_BT could be related, but it's clear that in case it's enabled, we're missing Link up event from the driver, the following lines in the log are missing:

[00:00:02.263,610] <inf> eth_w5500: w5500@0: Link up
[00:00:02.263,671] <dbg> net_ethernet: carrier_on_off: (sysworkq): Carrier ON for interface 0x20001380
[00:00:02.263,793] <dbg> net_if: update_operational_state: (sysworkq): iface 0x20001380, oper state UP admin UP carrier ON dormant OFF

It seems that the link detection in the driver takes place in a separate thread (

zephyr/drivers/ethernet/eth_w5500.c

Line 314 in 5f9a9ed

res = k_sem_take(&ctx->int_sem, K_MSEC(CONFIG_PHY_MONITOR_PERIOD));

, probably something's wrong in there, I'd try to debug if that thread has even a chance to run, maybe it's starved or something.

[wwilkins21]

Added some logs around that.

When in a normal working state:
[00:00:01.263,366] eth_w5500: Update link status: 0 Phycfgr: 0xba
[00:00:01.763,519] eth_w5500: Update link status: 0 Phycfgr: 0xba
[00:00:02.081,634] eth_w5500: Update link status: 0 Phycfgr: 0xbf
[00:00:02.081,634] eth_w5500: w5500@0: Link up
...
[00:00:14.694,854] eth_w5500: Update link status: 1 Phycfgr: 0xba
[00:00:14.694,885] eth_w5500: w5500@0: Link down

Hot plugging the cable works fine.

When I enable CONFIG_BT it's failing to read anything from the register.

[00:00:05.764,495] eth_w5500: Update link status: 0 Phycfgr: 0x00
[00:00:06.264,648] eth_w5500: Update link status: 0 Phycfgr: 0x00
[00:00:06.764,801] eth_w5500: Update link status: 0 Phycfgr: 0x00
[00:00:07.264,953] eth_w5500: Update link status: 0 Phycfgr: 0x00
[00:00:07.765,106] eth_w5500: Update link status: 0 Phycfgr: 0x00
[00:00:08.265,258] eth_w5500: Update link status: 0 Phycfgr: 0x00

The really odd part is that at boot, it does manage to initialize the w5500 when BT is enabled
[00:00:00.262,939] eth_w5500: W5500 Initialized
It's just after the w5500 thread the register reads fail.

[wwilkins21]

I did a couple changes to my board though nothing related to Ethernet. I'm no longer running into this issue anymore.

I did have to write up a static pm file due to BT creating a child image causing my partition definitions to be ignored, I don't think this is relevant but the only thing in my changes related to either Ethernet or BT.

Closing this issue as it seems to be an issue with my first revision board.