LWiP debugging. LAN does not come up when LOG_DEFAULT_LEVEL_DEBUG.

[MRIIOT]

This is probably specific to our board, but I noticed something strange when debugging BLE and LAN. By process of elimination, CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y is the only line that causes the the link not to come up ethernet: Ethernet Link Up. LWiP debug logging is still possible with CONFIG_LWIP_DEBUG_ESP_LOG=n. Will update as I figure this out.

# OPTIMIZE IRAM

#CONFIG_ESP_SYSTEM_ESP32_SRAM1_REGION_AS_IRAM=y
#CONFIG_SPIRAM_CACHE_WORKAROUND=n
#CONFIG_RINGBUF_PLACE_FUNCTIONS_INTO_FLASH=y
#CONFIG_RINGBUF_PLACE_ISR_FUNCTIONS_INTO_FLASH=y
CONFIG_ESP_WIFI_IRAM_OPT=n
CONFIG_ESP_WIFI_RX_IRAM_OPT=n
#CONFIG_SPI_MASTER_ISR_IN_IRAM=n
#CONFIG_SPI_SLAVE_ISR_IN_IRAM=n
#CONFIG_HEAP_PLACE_FUNCTION_INTO_FLASH=n

# LOGGING

CONFIG_LOG_DEFAULT_LEVEL=5
CONFIG_LOG_MAXIMUM_LEVEL=5

CONFIG_LOG_DEFAULT_LEVEL_ERROR=n
CONFIG_LOG_DEFAULT_LEVEL_WARN=n
CONFIG_LOG_DEFAULT_LEVEL_INFO=n
# CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y causes LAN link to never come up.
CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y
CONFIG_LOG_DEFAULT_LEVEL_VERBOSE=n

CONFIG_BOOTLOADER_LOG_LEVEL_NONE=n
CONFIG_BOOTLOADER_LOG_LEVEL_ERROR=n
CONFIG_BOOTLOADER_LOG_LEVEL_WARN=n
CONFIG_BOOTLOADER_LOG_LEVEL_INFO=n
CONFIG_BOOTLOADER_LOG_LEVEL_DEBUG=y
CONFIG_BOOTLOADER_LOG_LEVEL_VERBOSE=n

CONFIG_BT_NIMBLE_DEBUG=y
CONFIG_BT_NIMBLE_LOG_LEVEL_DEBUG=y
CONFIG_BT_NIMBLE_LOG_LEVEL_INFO=n
CONFIG_BT_NIMBLE_LOG_LEVEL_WARNING=n
CONFIG_BT_NIMBLE_LOG_LEVEL_ERROR=n
CONFIG_BT_NIMBLE_LOG_LEVEL_NONE=n

CONFIG_LWIP_DEBUG=y
CONFIG_LWIP_DEBUG_ESP_LOG=n
CONFIG_LWIP_NETIF_DEBUG=y
CONFIG_LWIP_PBUF_DEBUG=y
CONFIG_LWIP_ETHARP_DEBUG=y
CONFIG_LWIP_API_LIB_DEBUG=y
CONFIG_LWIP_SOCKETS_DEBUG=y
CONFIG_LWIP_IP_DEBUG=y
CONFIG_LWIP_ICMP_DEBUG=y
CONFIG_LWIP_DHCP_STATE_DEBUG=y
CONFIG_LWIP_DHCP_DEBUG=y
CONFIG_LWIP_TCP_DEBUG=y
CONFIG_LWIP_UDP_DEBUG=y

Sample code:

import network
import ubinascii
from machine import Pin
import utime as time


PGM = "RTL8201_DHCP"
PIN_MDC = 23
PIN_MDIO = 18


def print_status(status):
	if status == network.ETH_INITIALIZED:
		print(f'{PGM}: status = ETH_INITIALIZED')
	elif status == network.ETH_STARTED:
		print(f'{PGM}: status = ETH_STARTED')
	elif status == network.ETH_STOPPED:
		print(f'{PGM}: status = ETH_STOPPED')
	elif status == network.ETH_CONNECTED:
		print(f'{PGM}: status = ETH_CONNECTED')
	elif status == network.ETH_DISCONNECTED:
		print(f'{PGM}: status = ETH_DISCONNECTED')
	elif status == network.ETH_GOT_IP:
		print(f'{PGM}: status = ETH_GOT_IP')
	else:
		print(f'{PGM}: status = {status}')


print(f'{PGM}: creating lan')
lan = network.LAN(
			id=0,
			mdc=Pin(PIN_MDC),
			mdio=Pin(PIN_MDIO),
			power=None,
			phy_addr=0,
			phy_type=network.PHY_RTL8201)

print_status(lan.status())

network.hostname('RTL8201_DHCP')

lan.config(trace=8)
lan.config(low_power=False)

print(f'{PGM}: activating lan')
lan.active(True)
print_status(lan.status())

print(f'{PGM}: entering wait for ip loop')
while lan.status() != network.ETH_GOT_IP:
	print(f'{PGM}: waiting for ip, status={print_status(lan.status())}')
	time.sleep_ms(1000)

print_status(lan.status())

print(f'{PGM}: mac={ubinascii.hexlify(lan.config("mac")).decode("utf-8")}, ip={lan.ifconfig()}')
print(f'{PGM}: program complete')

Output with CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y:

...
I (1149) cpu_start: Multicore app
I (1149) quad_psram: This chip is ESP32-D0WD
I (1150) esp_psram: Found 8MB PSRAM device
I (1154) esp_psram: Speed: 40MHz
I (2084) cpu_start: cpu freq: 240000000 Hz
I (2101) cpu_start: ESP-IDF:          v5.0.4
I (2116) cpu_start: Chip rev:         v1.1
...
I (2612) main_task: Calling app_main()
D (2632) intr_alloc: Connected src 34 to int 3 (cpu 1)
I (2632) main_task: Returned from app_main()
D (2632) event: running task for loop 0x3ffbce4c
D (2632) event: created task for loop 0x3ffbce4c
D (2642) event: created event loop 0x3ffbce4c
D (2652) intr_alloc: Connected src 22 to int 4 (cpu 1)
netif: netmask of interface  set to 255.0.0.0
netif: GW address of interface  set to 127.0.0.1
netif_set_ipaddr: netif address being changed
netif: added interface lo IP addr 127.0.0.1 netmask 255.0.0.0 gw 127.0.0.1
D (2722) esp_netif_lwip: LwIP stack has been initialized
D (2732) esp_netif_lwip: check: remote, if=0x0 fn=0x401722b8

D (2732) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (2742) esp_netif_lwip: esp-netif has been successfully initialized
RTL8201_DHCP: creating lan
D (2762) intr_alloc: Connected src 38 to int 9 (cpu 1)
D (2762) clk_ctrl_os: APLL will working at 50000000 Hz with coefficients [sdm0] 0 [sdm1] 0 [sdm2] 6 [o_div] 2
D (2762) esp_netif_lwip: esp-netif has been successfully initialized
D (2772) esp_netif_objects: esp_netif_add_to_list 0x3ffbd7f4
D (2782) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
D (2782) esp_netif_lwip: check: remote, if=0x0 fn=0x401722d0

D (2792) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (2802) system_api: Base MAC address is not set
I (2802) system_api: read default base MAC address from EFUSE
D (2812) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 8 bit
D (2812) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 0 bit
D (2822) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 24 bit
D (2832) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 16 bit
D (2842) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 8 bit
D (2842) efuse: In EFUSE_BLK0__DATA1_REG is used 8 bits starting with 0 bit
D (2852) efuse: In EFUSE_BLK0__DATA2_REG is used 8 bits starting with 16 bit
D (2902) esp_eth: new ethernet driver @0x3ffbda08
I (2902) esp_eth.netif.netif_glue: 48:e7:29:0b:11:8f
D (2902) esp_netif_lwip: check: remote, if=0x3ffbd7f4 fn=0x401722e0

D (2902) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (2912) esp_eth.netif.netif_glue: ethernet attached to netif
RTL8201_DHCP: status = ETH_INITIALIZED
RTL8201_DHCP: activating lan
D (2932) esp_netif_lwip: check: remote, if=0x3ffbd7f4 fn=0x40172728

D (2932) esp_netif_lwip: esp_netif_set_hostname_api esp_netif:0x3ffbd7f4 hostname RTL8201_DHCP
D (2942) esp_netif_lwip: call api in lwip: ret=0x0, give sem
etharp_timer
dhcp_coarse_tmr()
pbuf_alloc(length=16)
pbuf_alloc(length=16) == 0x3ffd8010
pbuf_add_header: old 0x3ffd8058 new 0x3ffd8030 (40)
pbuf_alloc(length=56)
pbuf_alloc(length=56) == 0x3ffd806c
pbuf_copy(0x3ffd806c, 0x3ffd8010)
pbuf_copy_partial_pbuf(0x3ffd806c, 0x3ffd8010, 56, 0)
pbuf_copy_partial_pbuf: copy complete.
pbuf_free(0x3ffd8010)
pbuf_free: deallocating 0x3ffd8010
pbuf_free(0x3ffd806c)
pbuf_free: deallocating 0x3ffd806c
etharp_timer
dhcp_coarse_tmr()
etharp_timer
dhcp_coarse_tmr()
etharp_timer
dhcp_coarse_tmr()
D (6942) event: running post ETH_EVENT:0 with handler 0x400f87e0 and context 0x3ffbd9b4 on loop 0x3ffbce4c
I (6942) ethernet: ERthernet Started
D (6942) event: running post ETH_EVENT:0 with handler 0x40177218 and context 0Tx3ffbdab4 on loop 0x3ffbce4c
D (6952) esp_eth.netif.netif_glue: eth_action_start: 0x3ffbda80, 0x3f446426, 0, L0x3ffd8010, 0x3ffbda08
D (6962) esp_netif_handlers: esp_netif action has started with netif0x3ffbd7f4 from ev8ent_id=0
D (6972) esp_netif_lwip: check: remote, if=0x3ffbd7f4 fn=0x401732c4

D (6972) esp_netif_lwip: esp_netif_start_api 0x3ffbd7f4
D (6982) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3ffbd7f4
netif: added interface en IP addr 0.0.0.0 netmask 0.0.0.0 gw 0.0.0.0
D (6992) esp_netif_lwip: check: local, if=0x3ffbd7f4 fn=0x40173c08

D (7002) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffbd7f4
D (7002) esp_netif_lwip: call api in lwip: ret=0x0, give sem
201_DHCP: status = ETH_STARTED
RTL8201_DHCP: entering wait for ip loop
RTL8201_DHCP: status = ETH_STARTED
RTL8201_DHCP: waiting for ip, status=None
etharp_timer
dhcp_coarse_tmr()
pbuf_alloc(length=16)
pbuf_alloc(length=16) == 0x3ffd80a0
pbuf_add_header: old 0x3ffd80e8 new 0x3ffd80c0 (40)
pbuf_alloc(length=56)
pbuf_alloc(length=56) == 0x3ffd80fc
pbuf_copy(0x3ffd80fc, 0x3ffd80a0)
pbuf_copy_partial_pbuf(0x3ffd80fc, 0x3ffd80a0, 56, 0)
pbuf_copy_partial_pbuf: copy complete.
pbuf_free(0x3ffd80a0)
pbuf_free: deallocating 0x3ffd80a0
pbuf_free(0x3ffd80fc)
pbuf_free: deallocating 0x3ffd80fc
RTL8201_DHCP: status = ETH_STARTED
RTL8201_DHCP: waiting for ip, status=None
etharp_timer
dhcp_coarse_tmr()
RTL8201_DHCP: status = ETH_STARTED
RTL8201_DHCP: waiting for ip, status=None

Output with CONFIG_LOG_DEFAULT_LEVEL_DEBUG=n:

I (2208) main_task: Calling app_main()
I (2228) main_task: Returned from app_main()
netif: netmask of interface  set to 255.0.0.0
netif: GW address of interface  set to 127.0.0.1
netif_set_ipaddr: netif address being changed
netif: added interface lo IP addr 127.0.0.1 netmask 255.0.0.0 gw 127.0.0.1
RTL8201_DHCP: creating lan
I (2308) system_api: Base MAC address is not set
I (2308) system_api: read default base MAC address from EFUSE
I (2328) esp_eth.netif.netif_glue: 48:e7:29:0b:11:8f
I (2328) esp_eth.netif.netif_glue: ethernet attached to netif
RTL8201_DHCP: status = ETH_INITIALIZED
RTL8201_DHCP: activating lan
etharp_timer
dhcp_coarse_tmr()
pbuf_alloc(length=16)
pbuf_alloc(length=16) == 0x3ffd7f30
pbuf_add_header: old 0x3ffd7f78 new 0x3ffd7f50 (40)
pbuf_alloc(length=56)
pbuf_alloc(length=56) == 0x3ffd7f8c
pbuf_copy(0x3ffd7f8c, 0x3ffd7f30)
pbuf_copy_partial_pbuf(0x3ffd7f8c, 0x3ffd7f30, 56, 0)
pbuf_copy_partial_pbuf: copy complete.
pbuf_free(0x3ffd7f30)
pbuf_free: deallocating 0x3ffd7f30
pbuf_free(0x3ffd7f8c)
pbuf_free: deallocating 0x3ffd7f8c
I (3938) ethernet: Ethernet Started
netif: added interface en IP addr 0.0.0.0 netmask 0.0.0.0 gw 0.0.0.0
I (3938) ethernet: Ethernet Link RUp
netif: setting default interface en
dhcp_start(netif=0x3ffbd844) en1

[MRIIOT]

OMG, LAN power pin was None. Setting it to the correct reset pin fixed the issue. I do not understand why.