mcci-catena / arduino-lmic

LoraWAN-MAC-in-C library, adapted to run under the Arduino environment
https://forum.mcci.io/c/device-software/arduino-lmic/
MIT License
639 stars 208 forks source link

strange behaviour with ACK #458

Open thl-mot opened 5 years ago

thl-mot commented 5 years ago

I am using a slightly midified compliance-sketch. Main changes are UART.Interface to set the LoRaWAN registration parameters. I temporarely published the sketch on https://bitbucket.org/thl-mot/lmic-gpstracker I am testing with ttn. What I see:

  1. Device joines correctly
  2. Than it tries multiple times by increasing SF to send data
  3. after one recognized fail
  4. it send data as expected

log.txt

thl-mot commented 5 years ago

By the way, the distance between gateway and device is about 1m

terrillmoore commented 5 years ago

Sorry you're having problems.

Can you please send us a link to Amazon or whatever for purchasing a device? We are not seeing this kind of problem using Murata modules (non-ESP32), so my guess is that there's something different on timing based on the FreeRTOS integration..

The log shows that the device is behaving correctly, given that no messages are received. A correlated gateway log (showing downlink speeds) would be helpful. Unfortumately we'd need to ask you to also send the serial log.

Are you using LMIC_setClockError()? If so, what setting are you using?

thl-mot commented 5 years ago

I am using this device: https://primalcortex.wordpress.com/2017/11/24/the-esp32-oled-lora-ttgo-lora32-board-and-connecting-it-to-ttn/

LMIC_setClockError(1 * MAX_CLOCK_ERROR / 1000);

I also tried: LMIC_setClockError(1 * MAX_CLOCK_ERROR / 100);

thl-mot commented 5 years ago

I also assume that the behaviour curresponds with activation of ACK. I did't see that behaviour yesterday where I didn't send the data with ACK.

By the way, I discovered that every second try fails (see attached log below)

The gateway (TTN) shows one uplink, two downlink messages: SF12BW125, the neither downlink arrives in the device log.

send.log

terrillmoore commented 5 years ago

The downlink messages are very likely to be network messages, not application messages. The TTN Console doesn't show the details of these messages.

I would try setting the clock error to 5% to see whether that helps. I would also try removing the call to LMIC_setClockError(), and see if anything changes.

It is very curious that your timestamps are all very negative in the second log. On a normal Arduino platform, that indicates that millis() has overflowed, as it usually starts at zero. Your second log also shows use of 8 channels, which suggests that you received a downlink that setup the extra channels. The second link doesn't show any sign to me that RX succeeded. It's helpful to give succeeding logs as well as failing logs, to enable diagnosis.

We've not seen behavior like this -- but we've heard complaints about "RF quality" on the ESP32 boards. I'm not sure whether I'll be able to help without getting one of the boards.

terrillmoore commented 5 years ago

Unfortunately, the referenced webpage doesn't give a link to the seller, and there's lots of evidence that there are lots of similar boards from many vendors. I can't really help without a confirmed link to a reliable source. Thanks.

thl-mot commented 5 years ago

As each of my boards show different behaviour, I now switched to my own design. Its just a plain esp32 (WROOM-32U) and a RFM96 working on 868MHz. The connections match Arduino_LMIC::GetPinmap_ttgo_lora32_v1();.

There is still one thing that seams to be strange: Packet queued 12775757 (204412 ms): EV_TXSTART: ch=4 rps=0x01 (SF7 BW125 CR 4/5 Crc IH=0), datarate=5, opmode=888, txend=11115182, avail=10931987 12841642 (205466 ms): EV_RXSTART: freq=867.3 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate=5, opmode=888, txend=12779965, avail=10931987, delta ms 986 12906638 (206506 ms): EV_RXSTART: freq=869.5 rps=0x86 (SF12 BW125 CR 4/5 NoCrc IH=0), datarate=5, opmode=888, txend=12779965, avail=10931987, delta ms 2026 13193233 (211091 ms): EV_TXSTART: ch=5 rps=0x01 (SF7 BW125 CR 4/5 Crc IH=0), datarate=5, opmode=888, txend=13193340, avail=13084410 13259117 (212145 ms): EV_RXSTART: freq=867.5 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate=5, opmode=888, txend=13197440, avail=13084410, delta ms 986 13324113 (213185 ms): EV_RXSTART: freq=869.5 rps=0x86 (SF12 BW125 CR 4/5 NoCrc IH=0), datarate=5, opmode=888, txend=13197440, avail=13084410, delta ms 2026 13610709 (217771 ms): EV_TXSTART: ch=6 rps=0x02 (SF8 BW125 CR 4/5 Crc IH=0), datarate=4, opmode=888, txend=13610816, avail=13375359 13680257 (218884 ms): EV_RXSTART: freq=867.7 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate=4, opmode=888, txend=13618452, avail=13375359, delta ms 988 13745125 (219922 ms): EV_RXSTART: freq=869.5 rps=0x86 (SF12 BW125 CR 4/5 NoCrc IH=0), datarate=4, opmode=888, txend=13618452, avail=13375359, delta ms 2026 Received message on port 0: 0 bytes

If I'm Interpreting this log correctly. It seams that my device sends the data 3 times. On my (professional) LoRa platform (Zenner IoT Element IoT) there is only one up-transmission. This does not happen too often. But I can see it quite some times when debugging my code. If the esp32 device just had timing problems receiving the downlink-messages I would expect 3 UP-Messages and three Down messages, as my device triggers 3 valid ups. So my guess is, that either the transmission from my device is corrupted (bad antenna, ...) or the transmission is disturbed by some other lora or radio device.

terrillmoore commented 4 years ago

It looks like a confirmed message that is not getting acknowledged. (The data rate pattern is diagnostic of retries for a confirmed uplink.)