esp-idf-svc icon indicating copy to clipboard operation
esp-idf-svc copied to clipboard

Better error message that EthDriver does not work with DMA disabled

Open teamplayer3 opened this issue 2 years ago • 15 comments

When I use the EthDriver with Dma::Disabled, an error as follows is logged and for example a ping does not succeed.

I (2474) esp_idf_svc::ping: Ping timeout callback invoked
I (2474) esp_idf_svc::ping: From ??? icmp_seq=2 timeout
E (2854) spi_master: check_trans_valid(689): txdata transfer > host maximum
E (2854) w5500.mac: w5500_write(74): spi transmit failed
E (2864) w5500.mac: w5500_write_buffer(173): write TX buffer failed
E (2864) w5500.mac: emac_w5500_transmit(528): write frame failed

Related to 790fee01f9b70743dcfa46724b7ed34943832c66.

teamplayer3 avatar Nov 24 '22 18:11 teamplayer3

Dma::disabled imply that the frame_size is 64byte most Eth Frames with an MTU of 1500 or so are properbly to large here. If an Frame is longer than 64 bytes it can only be send in chucks or need Dma

Vollbrecht avatar Nov 24 '22 19:11 Vollbrecht

Ah ok, good to know. So, info like this belongs to docs at the end, I guess? Or is this knowledge which should be obtained from the esp-idf docs.

teamplayer3 avatar Nov 24 '22 20:11 teamplayer3

yeah thats documented in esp-idf doc. usually this is not a problem though because the esp-idf-hal driver should create chunks that are not larger than this and send it chunk by chunk even if you pass it a larger thing to send

Vollbrecht avatar Nov 24 '22 20:11 Vollbrecht

@teamplayer3 managed to get it working?

Now struggling myself with ETH w5500.

let eth = w5500::init_w5500(
        &sysloop,
        Box::new(EspEth::wrap(EthDriver::new_spi(
            peripherals.spi2,
            pins.gpio4, // int
            pins.gpio12, // sclk
            pins.gpio13, // sdo
            pins.gpio11, // sdi
            esp_idf_hal::spi::Dma::Auto(1500), // esp_idf_hal::spi::Dma::Disabled
            Some(pins.gpio10), // cs
            Option::<gpio::Gpio28>::None, //Some(pins.gpio39), // rst
            SpiEthChipset::W5500,
            36.MHz().into(),
            Some(&[0x02, 0x00, 0x00, 0x12, 0x34, 0x56]),
            Some(1),
            sysloop.clone(),
        )?)?),
    )?;

Basic example from esp-idf works. At first it fails of not getting HW id. and then after restart I get

Start w5500 mdns!
E (602) w5500.mac: w5500_reset(221): reset timeout
E (602) w5500.mac: emac_w5500_init(602): reset w5500 failed
I (602) gpio: GPIO[4]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
E (612) esp_eth: esp_eth_driver_install(214): init mac failed
I (612) esp_idf_svc::eventloop: Dropped
Error: ESP_ERR_TIMEOUT
E (1502) spi_master: check_trans_valid(689): txdata transfer > host maximum
E (1502) w5500.mac: w5500_read(97): spi transmit failed
E (1502) w5500.mac: w5500_read_buffer(188): read RX buffer failed

reinismu avatar Nov 25 '22 11:11 reinismu

Yes, I managed to get it working. I adjusted my driver settings to yours, and it works as well. For this, I use a netif with no dhcp, but it worked with dhcp as well.

EthDriver::new_spi(
  peripherals.spi2,
  pins.gpio1,
  pins.gpio2,
  pins.gpio3,
  pins.gpio4,
  Dma::Auto(1500), // Dma::Auto(4096),
  Some(pins.gpio5),
  Option::<Gpio6>::None, // Some(pins.gpio6),
  SpiEthChipset::W5500,
  36.MHz().into(),
  Some(&MAC_ADDR),
  Some(1),
  sysloop.clone(),
)

log

I (374) esp_idf_svc::eth: Driver initialized
I (374) esp_idf_svc::eth: Attached MAC address: [2, 0, 0, 18, 52, 86]
I (374) esp_idf_svc::eth: Initialization complete
I (384) static_ip: driver init
I (384) esp_idf_svc::eth: Stopping
E (394) esp_eth: esp_eth_stop(288): driver not started yet
I (394) esp_idf_svc::eth: Stop requested
I (404) esp_eth.netif.netif_glue: 02:00:00:12:34:56
I (404) esp_eth.netif.netif_glue: ethernet attached to netif
I (414) esp_idf_svc::eth: Start requested
I (414) esp_idf_svc::eth: About to wait for duration 20s
I (424) esp_idf_svc::eth: Waiting done - success
I (424) static_ip: Eth DHCP info: IpInfo { ip: 192.168.2.12, subnet: Subnet { gateway: 192.168.2.1, mask: Mask(24) }, dns: Some(8.8.8.8), secondary_dns: Some(8.8.4.4) }

But I have the problem after dropping EthDriver and sysloop esp-idf panics as described in #175.

Where is your EthDriver drop?

teamplayer3 avatar Nov 25 '22 11:11 teamplayer3

@teamplayer3 Could you show full example? I see that esp-idf-svc has changed a in last months. Before I had to do let netif_stack = Arc::new(EspNetifStack::new()?); to init netif. As I understand now it does automatically?

How does your sdkconfig looks like?

Where is your EthDriver drop? From what I can tell I don't drop it anywhere. Errors from driver come after chip restarts

reinismu avatar Nov 25 '22 12:11 reinismu

@teamplayer3 Could you show full example?

use std::{net::Ipv4Addr, time::Duration};

use anyhow::{bail, Result};

use embedded_svc::ipv4::{self, ClientSettings, Mask, Subnet};
use esp_idf_hal::{gpio::Gpio6, peripherals::Peripherals, spi::Dma, units::FromValueType};

use esp_idf_svc::{
    eth::{EspEth, EthDriver, EthWait, SpiEthChipset},
    eventloop::EspSystemEventLoop,
    netif::{EspNetif, NetifConfiguration},
    ping,
};

use log::*;

const MAC_ADDR: [u8; 6] = [0x02, 0x00, 0x00, 0x12, 0x34, 0x56];

fn main() -> Result<()> {
    esp_idf_sys::link_patches();

    // Bind the log crate to the ESP Logging facilities
    esp_idf_svc::log::EspLogger::initialize_default();

    let peripherals = Peripherals::take().unwrap();
    let pins = peripherals.pins;

    let sysloop = EspSystemEventLoop::take()?;

    let mut netif_config = NetifConfiguration::eth_default_client();
    netif_config.ip_configuration =
        ipv4::Configuration::Client(ipv4::ClientConfiguration::Fixed(ClientSettings {
            ip: Ipv4Addr::new(192, 168, 2, 12),
            subnet: Subnet {
                gateway: Ipv4Addr::new(192, 168, 2, 1),
                mask: Mask(24),
            },
            ..Default::default()
        }));
    let netif = EspNetif::new_with_conf(&netif_config)?;

    let eth_driver = EthDriver::new_spi(
        peripherals.spi2,
        pins.gpio1,
        pins.gpio2,
        pins.gpio3,
        pins.gpio4,
        Dma::Auto(1500), // Dma::Auto(4096),
        Some(pins.gpio5),
        Option::<Gpio6>::None, // Some(pins.gpio6),
        SpiEthChipset::W5500,
        36.MHz().into(),
        Some(&MAC_ADDR),
        Some(1),
        sysloop.clone(),
    )?;

    info!("driver init");

    let mut spi_ethernet = EspEth::wrap_all(eth_driver, netif)?;

    spi_ethernet.start()?;

    if !EthWait::new(spi_ethernet.driver(), &sysloop)?
        .wait_with_timeout(Duration::from_secs(20), || {
            spi_ethernet.is_started().unwrap()
        })
    {
        bail!("Eth did not receive a DHCP lease");
    }

    let ip_info = spi_ethernet.netif().get_ip_info()?;

    info!("Eth DHCP info: {:?}", ip_info);

    ping(Ipv4Addr::new(192, 168, 2, 34))?;

    Ok(())
}

// pings gateway
fn ping(ip: ipv4::Ipv4Addr) -> Result<()> {
    info!("About to do some pings for {:?}", ip);

    let ping_summary = ping::EspPing::default().ping(ip, &Default::default())?;
    if ping_summary.transmitted != ping_summary.received {
        bail!("Pinging IP {} resulted in timeouts", ip);
    }

    info!("Pinging done");

    Ok(())
}

How does your sdkconfig looks like?

sdkconfig

# Necessary for the LED screen demos
CONFIG_ESP_MAIN_TASK_STACK_SIZE=7000

CONFIG_ESP_SYSTEM_EVENT_TASK_STACK_SIZE=4096

# NAPT demo (router)
CONFIG_LWIP_L2_TO_L3_COPY=y
CONFIG_LWIP_IP_FORWARD=y
CONFIG_LWIP_IPV4_NAPT=y

# SPI Ethernet demo
CONFIG_ETH_SPI_ETHERNET_DM9051=y
CONFIG_ETH_SPI_ETHERNET_W5500=y
CONFIG_ETH_SPI_ETHERNET_KSZ8851SNL=y

# Bigger headers are necessary for the QEMU demo
CONFIG_HTTPD_MAX_URI_LEN=1024
CONFIG_HTTPD_MAX_REQ_HDR_LEN=2048

# Workaround for https://github.com/espressif/esp-idf/issues/7631 (Fixed)
CONFIG_MBEDTLS_CERTIFICATE_BUNDLE=y
CONFIG_MBEDTLS_CERTIFICATE_BUNDLE_DEFAULT_FULL=y

# Workaround for the experimental HTTP(S) TLS client demo
CONFIG_ESP_TLS_INSECURE=y
CONFIG_ESP_TLS_SKIP_SERVER_CERT_VERIFY=y

# Future: proper back-trace for esp32c3
#CONFIG_ESP_SYSTEM_USE_EH_FRAME=y

As I understand now it does automatically?

Now if you create a netif: EspNetif::new_with_conf() for example, it initializes the netif stack once.

teamplayer3 avatar Nov 25 '22 13:11 teamplayer3

@teamplayer3 Thanks! Doing some testing, but still can't get it to work

I (408) esp_idf_svc::eth: Driver initialized
I (408) esp_idf_svc::eth: Attached MAC address: [2, 0, 0, 18, 52, 86]
I (408) esp_idf_svc::eth: Initialization complete
I (418) w5500_mdns: driver init
I (418) esp_idf_svc::eth: Stopping
E (428) esp_eth: esp_eth_stop(288): driver not started yet
I (428) esp_idf_svc::eth: Stop requested
I (438) esp_eth.netif.netif_glue: 02:00:00:12:34:56
I (438) esp_eth.netif.netif_glue: ethernet attached to netif
I (448) esp_idf_svc::eth: Start requested
E (448) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0)
I (458) esp_idf_svc::eth: About to wait for duration 20s
I (468) esp_idf_svc::eth: Waiting done - success
I (468) w5500_mdns: Eth DHCP info: IpInfo { ip: 192.168.17.254, subnet: Subnet { gateway: 192.168.17.1, mask: Mask(24) }, dns: Some(8.8.8.8), secondary_dns: Some(8.8.4.4) }
I (488) w5500_mdns: About to do some pings for 192.168.17.1
I (488) esp_idf_svc::ping: About to run a summary ping 192.168.17.1 with configuration Configuration { count: 5, interval: 1s, timeout: 1s, data_size: 56, tos: 0 }
I (508) esp_idf_svc::ping: Ping session established, got handle 0x3fce4318
E (518) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0)
I (528) esp_idf_svc::ping: Ping session started
I (528) esp_idf_svc::ping: Waiting for the ping session to complete
E (1388) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0)
I (1528) esp_idf_svc::ping: Ping timeout callback invoked
I (1528) esp_idf_svc::ping: From ??? icmp_seq=1 timeout
E (2388) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0)
I (2528) esp_idf_svc::ping: Ping timeout callback invoked
I (2528) esp_idf_svc::ping: From ??? icmp_seq=2 timeout
E (3388) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0)
I (3528) esp_idf_svc::ping: Ping timeout callback invoked
I (3528) esp_idf_svc::ping: From ??? icmp_seq=3 timeout
E (3528) ping_sock: send error=0
E (4388) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0)
I (4528) esp_idf_svc::ping: Ping timeout callback invoked
I (4528) esp_idf_svc::ping: From ??? icmp_seq=4 timeout
E (4528) ping_sock: send error=0
I (5528) esp_idf_svc::ping: Ping timeout callback invoked
I (5528) esp_idf_svc::ping: From ??? icmp_seq=5 timeout
I (5528) esp_idf_svc::ping: Ping end callback invoked
I (5528) esp_idf_svc::ping: 3 packets transmitted, 0 received, time 4988ms
I (5538) esp_idf_svc::ping: Ping session stopped
I (5538) esp_idf_svc::ping: Ping session 0x3fce4318 removed
I (5548) esp_idf_svc::eth: Stopping
I (5558) esp_idf_svc::eth: Stop requested
I (5558) esp_idf_svc::eth: Stopping

Seems like something is wrong with w5500 driver

reinismu avatar Dec 01 '22 11:12 reinismu

First I think the error E (4388) w5500.mac: emac_w5500_transmit(523): free size (42) < send length (0) is wrong implemented in esp-idf.

https://github.com/espressif/esp-idf/blob/master/components/esp_eth/src/esp_eth_mac_w5500.c#L473

I think free size and send length is reversed as args, but I'm not shure if the args are intentionally passed in reversed order.

But then it's strange why free size is 0.

teamplayer3 avatar Dec 01 '22 19:12 teamplayer3

Ye seems like a small bug there.

Thought I have something wrong with wires, but the C version works for me. I'm pretty lost :/ Waiting for the PCB to be assembled and will test on it.

I guess I could ditch esp32 implementation and switch to pure rust driver for w5500, but then I might need to do custom HTTP etc as well

reinismu avatar Dec 01 '22 19:12 reinismu

When you use a bare metal w5500 driver you can use smoltcp for the http stuff I think.

Or you can test the w5500 device driver. I think this driver is doing the http stuff for you.

teamplayer3 avatar Dec 01 '22 19:12 teamplayer3

Tried to communicate with w5500 manually. It gave me back some garbage signals. C example works perfectly fine, so board and GPIO is fine.

lost

reinismu avatar Jan 16 '23 14:01 reinismu

Tried to communicate with w5500 manually

Can you show your implementation?

teamplayer3 avatar Jan 16 '23 15:01 teamplayer3

@reinismu how is the status on your side? get it working now ?

Vollbrecht avatar Mar 29 '23 15:03 Vollbrecht

It will never work with DMA disabled. It is more about shall we give a better info to the user that this is the case.

ivmarkov avatar Mar 29 '23 17:03 ivmarkov