Failed to claim receiving frame N: expected state ...

[jbbjarnason]

Do you have any idea what could be going wrong here:

[2024-12-19T22:03:28Z INFO  ethercat] Ethercat tick interval: 1.006951ms
[2024-12-19T22:03:28Z INFO  ethercat] Tx/Rx duration: 293.239µs
[2024-12-19T22:03:28Z INFO  ethercat] Process data duration: 274.091µs
[2024-12-19T22:03:29Z WARN  ethercat] Failed to tx/rx: timeout
[2024-12-19T22:03:29Z ERROR ethercrab::pdu_loop::frame_element] Failed to claim receiving frame 2: expected state Sent, but got None
[2024-12-19T22:03:29Z ERROR ethercrab::std::unix] Failed to receive frame: pdu: invalid PDU index 2
[2024-12-19T22:03:29Z ERROR ethercat] TX/RX task: ReceiveFrame

    Critical error: PanicHookInfo {
        payload: Any { .. },
        location: Location {
            file: "ethercat/src/bus.rs",
            line: 112,
            col: 18,
        },
        can_unwind: true,
        force_no_backtrace: false,
    }

This occurs both with tx_rx_task and iouring

[jamwaffles]

Can you send a Wireshark capture of the entire run when you receive that panic please? I'd also like to know what version/commit hash of EtherCrab you're running and, if possible, as much of the Rust source as you can share. This might be an internal race condition and I've seen it before, but it's difficult to reproduce without the original setup.

[jbbjarnason]

Thank you for the quick response,

We were able to get it running a bit longer with wait_loop_delay set to 1ms instead of the default 0.

The source code is here: https://github.com/centroid-is/tfc/blob/test/tfc-exes/ethercat/src/bus.rs#L109

Here are trace logs and pcap dump
logs.tar.gz

We are running this on

Vendor ID:                GenuineIntel
  Model name:             Intel(R) Celeron(R) J6412 @ 2.00GHz


Settings for enp3s0:
	Supported ports: [ TP ]
	Supported link modes:   10baseT/Half 10baseT/Full
	                        100baseT/Half 100baseT/Full
	                        1000baseT/Full
	                        2500baseT/Full
	Supported pause frame use: Symmetric
	Supports auto-negotiation: Yes
	Supported FEC modes: Not reported
	Advertised link modes:  10baseT/Half 10baseT/Full
	                        100baseT/Half 100baseT/Full
	                        1000baseT/Full
	                        2500baseT/Full
	Advertised pause frame use: Symmetric
	Advertised auto-negotiation: Yes
	Advertised FEC modes: Not reported
	Speed: 100Mb/s
	Duplex: Full
	Auto-negotiation: on
	Port: Twisted Pair
	PHYAD: 0
	Transceiver: internal
	MDI-X: Unknown
netlink error: Operation not permitted
        Current message level: 0x00000007 (7)
                               drv probe link
	Link detected: yes


ethtool -c enp3s0
Coalesce parameters for enp3s0:
Adaptive RX: n/a  TX: n/a
stats-block-usecs:	n/a
sample-interval:	n/a
pkt-rate-low:		n/a
pkt-rate-high:		n/a

rx-usecs:	0
rx-frames:	n/a
rx-usecs-irq:	n/a
rx-frames-irq:	n/a

tx-usecs:	0
tx-frames:	n/a
tx-usecs-irq:	n/a
tx-frames-irq:	n/a

rx-usecs-low:	n/a
rx-frame-low:	n/a
tx-usecs-low:	n/a
tx-frame-low:	n/a

rx-usecs-high:	n/a
rx-frame-high:	n/a
tx-usecs-high:	n/a
tx-frame-high:	n/a

CQE mode RX: n/a  TX: n/a

tx-aggr-max-bytes:	n/a
tx-aggr-max-frames:	n/a
tx-aggr-time-usecs:	n/a

[jamwaffles]

Thanks very much, this is perfect!

Note to self:

ethercrab = "0.5.0"
ethercrab-wire = "0.2.0"

[jbbjarnason]

sorry forgot to add that, i will try 0.5.1

[jbbjarnason]

logs2.tar.gz
here is running version 0.5.1

[jamwaffles]

@jbbjarnason could you please try this in your Cargo.toml:

ethercrab = { git = "https://github.com/ethercrab-rs/ethercrab.git", rev = "52b570f3690f5d20605f69758d57b8d3860dd93d" }

It's the latest commit in #260. I don't have a way to reproduce your original issue on my test bench so this change is an educated guess. Please let me know if it works or not, and I'd appreciate all the usual logs, Wireshark captures, etc either way :)

[jbbjarnason]

@jamwaffles it seems like I am unable to reproduce the error now with wait_loop_delay as 1ms

I tried lower wait_loop_delay like 100us and it produces spam of the log when I have debug logs enabled

[2024-12-21T08:49:23Z ERROR ethercrab::pdu_loop::storage] No available frames in 16 slots
[2024-12-21T08:49:23Z WARN  ethercat] Failed to tx/rx: pdu: failed to swap frame state

I tried trace logs and it panicked but differently than yesterday, I have attached both cases of logs.

logs.debug.wait_loop_delay_100us.tar.gz
logs.trace.wait_loop_delay_100us.tar.gz

[jamwaffles]

Great that the original problem is gone! As for the error, try increasing MAX_FRAMES. You can have up to 255 as long as the number is a power of two. At a guess, something in your code is trying to send frames too quickly (are you using any concurrent tasks?) and EtherCrab is running out of slots to use. You also shouldn't need a wait loop delay as short as 100us. Is there a reason you're trying to minimise the wait delay? Are you perhaps trying to read SDOs in the process data cycle?

[jbbjarnason]

Good to know about the MAX_FRAMES, I have the ethercat network in just the regular two tasks, however it is trying to initialize but fails on working counter therefore goes through the initialization cycle again and again (this is not a problem with 1ms wait_loop_delay).

No reason for lowering the wait loop delay, I was only trying to reproduce the previous error.

I am not currently reading or writing sdo in pdo but that is something I would like to being able to do, like nonfrequent read or writes. Example, adjusting current limit in some frequency drive without restarting the program.

[jamwaffles]

The recommended way to update SDOs is to map them into the PDI if possible. I (and the ETG generally) would advise against doing any SDO reads/writes using CoE in the process data cycle as they take a long time (relatively), although some SubDevices don't support mapping certain SDOs which is annoying.

EtherCrab doesn't currently allow this, but ideally you'd spawn a separate task to do the SDO stuff in, which runs alongside the process data loop. I'm thinking about how to modify the API to allow this however.

[jbbjarnason]

That would be really nice, I would like the process data drivers to internally do as little as possible so delegating user inputs for sdo writes/reads to different asynchrounus task would be great.

[jamwaffles]

I've just released this change in v0.5.2. Please cargo update and make sure you're on at least 0.5.2 (e.g. cargo tree -i ethercrab).