embassy-rs / lora-phy

REPO ARCHIVED - moved to https://github.com/lora-rs/lora-rs -- LoRa implementation based on embedded-hal-async
Apache License 2.0
23 stars 15 forks source link

LoRa Receive Soft Lock #27

Closed ProjectInitiative closed 12 months ago

ProjectInitiative commented 12 months ago

Summary

When running this example, there is a soft lock. It can be reproduced by sending another message while the match is waiting, the rx function get stuck, and cannot receive any more messages until the micro controller is reset.

Hardware Summary

Steps to reproduce

Copy line 89 - 98 and paste after line 98 in the lora_p2p_send.rs file.

Compile and load on the respective pico devices, and after the first message, any messages sent after are lost, and the receive loop does not continue.

Trace Log ```bash (HOST) INFO flashing program (14 pages / 56.00 KiB) (HOST) INFO success! (HOST) WARN insufficient DWARF info; compile your program with `debug = 2` to enable location info (HOST) WARN `defmt::timestamp!` implementation was found, but timestamp is not part of the log format; ──────────────────────────────────────────────────────────────────────────────── TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[c0, 0] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[9d, 1] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[80, 0] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8a, 1] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 7, 40, 14, 24] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[97, 1, 0, 2, 80] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[96, 1] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8f, 0, 0] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[1d, 8, d8, 0] └─ @ :0 TRACE read 1: 0x[c8] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 8, d8, de] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[95, 4, 7, 0, 1] └─ @ :0 DEBUG tx power = 0 └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8e, 0, 4] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8, ff, ff, ff, ff, 0, 0, 0, 0] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[1d, 2, 9f, 0] └─ @ :0 TRACE read 9: 0x[0, 44, 11, ff, a3, b0, ed, 18, 7] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 2, 9f] 0x[1, 8, ac, ff, a3, b0, ed, 18, 7] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[1d, 2, 9f, 0] └─ @ :0 TRACE read 9: 0x[1, 8, ac, ff, a3, b0, ed, 18, 7] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 2, 9f] 0x[2, 8, ac, 8, 89, b0, ed, 18, 7] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 DEBUG sf = 10, bw = 5, cr = 4 └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8b, a, 5, 4, 0] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[1d, 8, 89, 0] └─ @ :0 TRACE read 1: 0x[5] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 8, 89, 5] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8c, 0, 4, 0, 64, 1, 0] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[98, e1, e9] └─ @ :0 DEBUG channel = 903900000 └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[86, 38, 7e, 66, 66] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[8, ff, ff, ff, ff, 0, 0, 0, 0] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[9f, 0] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[a0, 0] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[1d, 7, 36, 0] └─ @ :0 TRACE read 1: 0x[d] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 7, 36, d] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[d, 8, ac, 94] └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[82, ff, ff, ff] └─ @ :0 DEBUG Loop intera └─ @ :0 DEBUG process_irq loop entered └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE EdgeHigh for pin 20 was cleared, return Poll::Ready └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[12] └─ @ :0 TRACE read 2 status 0xd2: 0x[0, 4] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[2, 0, 4] └─ @ :0 DEBUG process_irq satisfied: irq_flags = 0x4 in radio mode Receive └─ @ :0 DEBUG PreambleDetected in radio mode Receive └─ @ :0 DEBUG process_irq loop entered └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE EdgeHigh for pin 20 was cleared, return Poll::Ready └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[12] └─ @ :0 TRACE read 2 status 0xd2: 0x[0, 10] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[2, 0, 10] └─ @ :0 DEBUG process_irq satisfied: irq_flags = 0x10 in radio mode Receive └─ @ :0 DEBUG HeaderValid in radio mode Receive └─ @ :0 DEBUG process_irq loop entered └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 TRACE EdgeHigh for pin 20 was cleared, return Poll::Ready └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[12] └─ @ :0 TRACE read 2 status 0xd4: 0x[0, 2] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[2, 0, 2] └─ @ :0 DEBUG process_irq satisfied: irq_flags = 0x2 in radio mode Receive └─ @ :0 DEBUG RxDone in radio mode Receive └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[13] └─ @ :0 TRACE read 2 status 0xd4: 0x[3, 0] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[1e, 0, 0] └─ @ :0 TRACE read 3: 0x[1, 2, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] └─ @ :0 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ @ :0 TRACE write: 0x[14] └─ @ :0 TRACE read 3 status 0xd4: 0x[b8, 21, ba] └─ @ :0 INFO rx successful └─ @ :0 DEBUG Loop intera └─ @ :0 DEBUG process_irq loop entered └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0 ```
ceekdee commented 12 months ago

Is this a debug statement you added? I am not picking it up in embassy or lora-phy.

DEBUG Loop intera

ProjectInitiative commented 12 months ago

Oh yes, my mistake, I added an additional debug to the example to try and see where the iteration was hanging. I added that between lines 96 and 97 of the recv example.

ceekdee commented 12 months ago

If this is indeed the end of the trace:

TRACE read 3 status 0xd4: 0x[b8, 21, ba] └─ @ :0 INFO rx successful └─ @ :0 DEBUG Loop intera └─ @ :0 DEBUG process_irq loop entered └─ @ :0 TRACE InputFuture::poll return Poll::Pending └─ @ :0

it seems to indicate the polling on the DIO pin (looking for it to go high) is terminating after one poll.

Please provide the revision of Embassy in GitHub which is being used for this test.

Also, if you run normal lora_p2p_send with a delay between runs, does lora_p2p_receive pick up each transmission?

ProjectInitiative commented 12 months ago

This is from my Cargo.lock file: git+https://github.com/embassy-rs/lora-phy?rev=1323eccc1c470d4259f95f4f315d1be830d572a3#1323eccc1c470d4259f95f4f315d1be830d572a3

Going to re run tests on newest release. I see there is version 2?

I ran the examples over night twice, and that is how I discovered the issue, because at some point the receive got stuck.

ProjectInitiative commented 12 months ago

For the sake of sanity, I cloned a clean repo of the embassy repo. Here is the stack trace:

TRACE LOG
```bash 0.042856 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.042933 TRACE write: 0x[c0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.043067 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043096 TRACE write: 0x[9d, 1] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.043190 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043246 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043271 TRACE write: 0x[80, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.043364 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043411 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043437 TRACE write: 0x[8a, 1] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.043560 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043589 TRACE write: 0x[d, 7, 40, 14, 24] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.043707 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043753 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043777 TRACE write: 0x[97, 1, 0, 2, 80] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.043886 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043919 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.043945 TRACE write: 0x[96, 1] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.044044 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.044077 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.044100 TRACE write: 0x[8f, 0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.044407 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.044455 TRACE write: 0x[1d, 8, d8, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:102 0.044496 TRACE read 1: 0x[c8] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:112 0.044630 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.044661 TRACE write: 0x[d, 8, d8, de] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.044796 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.044850 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.044873 TRACE write: 0x[95, 4, 7, 0, 1] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.044918 DEBUG tx power = 0 └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:444 0.045001 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.045034 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.045060 TRACE write: 0x[8e, 0, 4] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.045239 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.045264 TRACE write: 0x[8, ff, ff, ff, ff, 0, 0, 0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.045709 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.045747 TRACE write: 0x[1d, 2, 9f, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:102 0.045777 TRACE read 9: 0x[0, 64, 11, ff, a3, f0, ed, 18, 27] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:112 0.045998 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.046030 TRACE write: 0x[d, 2, 9f] 0x[1, 8, ac, ff, a3, f0, ed, 18, 27] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:44 0.046469 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.046506 TRACE write: 0x[1d, 2, 9f, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:102 0.046535 TRACE read 9: 0x[1, 8, ac, ff, a3, f0, ed, 18, 27] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:112 0.046739 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.046768 TRACE write: 0x[d, 2, 9f] 0x[2, 8, ac, 8, 89, f0, ed, 18, 27] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:44 0.046961 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047026 DEBUG sf = 10, bw = 5, cr = 4 └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:459 0.047130 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047184 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047225 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047249 TRACE write: 0x[8b, a, 5, 4, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.047420 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047455 TRACE write: 0x[1d, 8, 89, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:102 0.047485 TRACE read 1: 0x[5] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:112 0.047600 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047628 TRACE write: 0x[d, 8, 89, 5] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.047768 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047814 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047835 TRACE write: 0x[8c, 0, 4, 0, 64, 1, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.047932 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.047963 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061091 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061116 TRACE write: 0x[98, e1, e9] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.061157 DEBUG channel = 903900000 └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:544 0.061280 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061311 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061376 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061400 TRACE write: 0x[86, 38, 7e, 66, 66] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.061568 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061594 TRACE write: 0x[8, ff, ff, ff, ff, 0, 0, 0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.061704 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061743 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061769 TRACE write: 0x[9f, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.061856 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061892 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.061918 TRACE write: 0x[a0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.062125 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.062160 TRACE write: 0x[1d, 7, 36, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:102 0.062193 TRACE read 1: 0x[d] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:112 0.062315 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.062344 TRACE write: 0x[d, 7, 36, d] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.062459 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.062487 TRACE write: 0x[d, 8, ac, 94] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.062593 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.062633 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.074245 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 0.074270 TRACE write: 0x[82, ff, ff, ff] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 0.074340 DEBUG process_irq loop entered └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:832 0.074376 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.907678 TRACE EdgeHigh for pin 20 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.907933 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.907968 TRACE write: 0x[12] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:167 2.908000 TRACE read 2 status 0xd2: 0x[0, 4] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:177 2.908131 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.908158 TRACE write: 0x[2, 0, 4] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 2.908199 DEBUG process_irq satisfied: irq_flags = 0x4 in radio mode Receive └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:850 2.908242 DEBUG PreambleDetected in radio mode Receive └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:859 2.908281 DEBUG process_irq loop entered └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:832 2.908304 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.908341 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.960580 TRACE EdgeHigh for pin 20 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.960769 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.960799 TRACE write: 0x[12] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:167 2.960824 TRACE read 2 status 0xd2: 0x[0, 10] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:177 2.960927 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.960957 TRACE write: 0x[2, 0, 10] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 2.960988 DEBUG process_irq satisfied: irq_flags = 0x10 in radio mode Receive └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:850 2.961013 DEBUG HeaderValid in radio mode Receive └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:856 2.961036 DEBUG process_irq loop entered └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:832 2.961056 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.961093 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.993419 TRACE EdgeHigh for pin 20 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.993598 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.993626 TRACE write: 0x[12] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:167 2.993650 TRACE read 2 status 0xd4: 0x[0, 2] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:177 2.993748 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.993777 TRACE write: 0x[2, 0, 2] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:43 2.993805 DEBUG process_irq satisfied: irq_flags = 0x2 in radio mode Receive └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:850 2.993831 DEBUG RxDone in radio mode Receive └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:882 2.994037 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.994064 TRACE write: 0x[13] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:167 2.994088 TRACE read 2 status 0xd4: 0x[3, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:177 2.994341 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.994380 TRACE write: 0x[1e, 0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:102 2.994410 TRACE read 3: 0x[1, 2, 3, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:112 2.994745 TRACE LevelLow for pin 2 was cleared, return Poll::Ready └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 2.994777 TRACE write: 0x[14] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:167 2.994801 TRACE read 3 status 0xd4: 0x[8c, 21, 8c] └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/interface.rs:177 2.994863 INFO rx successful └─ src/bin/lora_p2p_receive.rs:105 7.994925 DEBUG process_irq loop entered └─ /home/kpzak/.cargo/git/checkouts/lora-phy-eb526861eb331585/1323ecc/src/sx1261_2/mod.rs:832 7.994952 TRACE InputFuture::poll return Poll::Pending └─ /home/kpzak/development/build-software/embassy/embassy-rp/src/fmt.rs:117 ```
ceekdee commented 12 months ago

Thank you for re-creating the issue with the current Embassy revision. The trace tells the same story: polling for the DIO1 interrupt pin going high seems to terminate, or there is an error in handling that event, or the logging itself fails.

I'll attempt to recreate it in my testbed and debug it further. I may need to request assistance from the Embassy team.

There is a lora-phy version 2, but there should be no difference in how it handles a read continuous operation. Embassy will be updated to use version 2 once another Embassy dependency is updated.

ceekdee commented 12 months ago

In your local Embassy clone, can you make a code change and re-test?

https://github.com/embassy-rs/embassy/blob/2c38dd17b9a5a507fc77d90d78486e4764234752/embassy-lora/src/iv.rs#L286

Take out the check for the LoRa board (BoardType::RpPicoWaveshareSx1262) so that only the following is executed:

self.dio1.wait_for_high().await.maperr(|| DIO1)?;

That is, always wait for high.

This comes from a suggestion posted in the Embassy chat as a result of the question I raised there.

ProjectInitiative commented 12 months ago

That appears to work. going to run another overnight test!

ceekdee commented 12 months ago

If the overnight test verifies the fix, I will make a PR for the embassy-lora crate.

ProjectInitiative commented 12 months ago

Probably don't need an overnight test. I had it running all day, haven't seen a single error or hang. Will continue if desired.

ceekdee commented 12 months ago

Seems to be a sufficient test. Thank you! I'll work on a PR for embassy-lora and note that here when it is opened.

ceekdee commented 12 months ago

Issue closed with PR applied to Embassy.