search

lorabasics / basicstation

LoRa Basics™ Station - The LoRaWAN Gateway Software
https://doc.sm.tc/station
Other
340 stars 178 forks source link

CRC fail error with RAK2247 #173

Open Nileshbhavsar opened 1 year ago

Nileshbhavsar commented 1 year ago

Hi,

I am using RAK 2247 through SPI with my custom board. I am trying to use inbuilt LNS in my gateway and for that I have done all producers as per readme file.

When I run it using "/opt/ttn-station/basicstation/build-rpi-std/bin/station --radio-init=/opt/ttn-station/reset_gw.sh" command then it start running properly but when I am trying to send any join request or data from node device, at that time getting CRC failed error. Please check below.

2022-10-06 04:43:35.630 [S2E:VERB] RX 865.4025MHz DR0 SF12/BW125 snr=9.2 rssi=-33 xtime=0xCE000008FD5104 - jreq MHdr=00 JoinEui=::0 DevEui=8c1f:644d:a001:4d10 DevNonce=26309 MIC=721429268
2022-10-06 04:43:37.643 [S2E:WARN] Received 'dnmsg' before 'router_config' - dropped
2022-10-06 04:43:57.474 [SYN:INFO] MCU/SX130X drift stats: min: +0.0ppm  q50: +1.0ppm  q80: +1.4ppm  max: +2.4ppm - threshold q90: +1.9ppm
2022-10-06 04:43:57.474 [SYN:INFO] Mean MCU drift vs SX130X#0: 0.8ppm
2022-10-06 04:44:14.279 [SYN:INFO] Time sync qualities: min=101 q90=108 max=109 (previous q90=109)
2022-10-06 04:44:39.488 [SYN:INFO] MCU/SX130X drift stats: min: +0.0ppm  q50: +1.0ppm  q80: +1.4ppm  max: +1.9ppm - threshold q90: +1.9ppm
2022-10-06 04:44:39.488 [SYN:INFO] Mean MCU drift vs SX130X#0: 0.9ppm
2022-10-06 04:44:54.193 [SYN:VERB] Time sync rejected: quality=113 threshold=108
2022-10-06 04:45:01.016 [RAL:DEBU] [CRC FAIL] 866.585MHz -12.00/-106.0 SF7/BW125 (mod=16/dr=2/bw=3) xtick=0e14b424 (236237860) 33 bytes: 75E84490427794280B39E784182931F5B33E06A9558BA2486448BD77E0DC3FE553
2022-10-06 04:45:02.596 [SYN:VERB] Time sync rejected: quality=118 threshold=108
2022-10-06 04:45:17.300 [SYN:INFO] Time sync qualities: min=101 q90=107 max=118 (previous q90=108)

Herewith I attach full log file also. crc_error.txt This same device working fine with packet forwarder mode. Please help me to resolve this ASAP.

beitler commented 1 year ago

Hi @Nileshbhavsar ,

thanks for submitting the issue. The root cause is the fact that the LNS specifies IN865 inside the router_config structure. This is an unsupported region specifier at this time. 

2022-10-06 04:41:03.958 [S2E:WARN] Unrecognized region: IN865 - ignored

This causes future downlink messages to be dropped

2022-10-06 04:43:37.643 [S2E:WARN] Received 'dnmsg' before 'router_config' - dropped

This is why your device is not joining. I don't think that the CRC error plays a role here.

Please have a look at issue #162 if you are interested in a workaround. This issue will be fixed in the next release.

Nileshbhavsar commented 1 year ago

Hi,

Thanks for your response.

As per my knowledge, I am using latest version 2.0.6. Still can you guide me how to check version?

In above share problem loop, This problem happened due to not added region in this version but we can still run using change line in s2e.c file. Am i right?

If yes, I found similar line in basicstation/src/s2e.c 1794 not in 1804. Please confirm once.

beitler commented 1 year ago

You can check the version by running station --version.

Exactly, the work around is to change this line https://github.com/lorabasics/basicstation/blob/ba4f85d80a438a5c2b659e568cd2d0f0de08e5a7/src/s2e.c#L1794

to 

if( s2ctx->txpow == 0 && (msgtype == J_dnmsg || msgtype == J_dnsched || msgtype == J_dnframe) ) {

Here is a patch

diff --git a/src/s2e.c b/src/s2e.c
index 6a9c009..879d3c9 100644
--- a/src/s2e.c
+++ b/src/s2e.c
@@ -1791,7 +1791,7 @@ int s2e_onMsg (s2ctx_t* s2ctx, char* json, ujoff_t jsonlen) {
         LOG(MOD_S2E|ERROR, "Parsing of JSON message failed - ignored");
         return 1;   // return fail? would trigger a reconnect
     }
-    if( s2ctx->region == 0 && (msgtype == J_dnmsg || msgtype == J_dnsched || msgtype == J_dnframe) ) {
+    if( s2ctx->txpow == 0 && (msgtype == J_dnmsg || msgtype == J_dnsched || msgtype == J_dnframe) ) {
         // Might happen if messages are still queued
         LOG(MOD_S2E|WARNING, "Received '%.*s' before 'router_config' - dropped", D.str.len, D.str.beg);
         return 1;
Nileshbhavsar commented 1 year ago

Hi,

Thank you for you response.

I would like to share my results with you. Now problem has been resolved. Thank you for kind support. Now, I want to implement same thing with RAK 5146 which having SX1303 chip. How can i do with that?

beitler commented 1 year ago

Great. Thanks for the feedback.

SX1303 is also supported with the corecell HAL. So, the same station binary should work, just configure the device accordingly in the station.conf file. Check out the documentation about how to specify if your device is communicating SPI oder USB.

Nileshbhavsar commented 1 year ago

Hi,

I tried corecell with RAK 5146 but unfortunately failed with I2c temperature sensor error. Please check below log.

root@rak-gateway:/opt/ttn-station# RADIODEV=/dev/spidev0.0 /opt/ttn-station/basicstation/build-corecell-std/bin/station
2022-10-07 05:23:26.020 [SYS:INFO] Logging     : stderr (maxsize=10000000, rotate=3)
2022-10-07 05:23:26.021 [SYS:INFO] Station Ver : 2.0.6(corecell/std) 2022-09-28 11:22:25
2022-10-07 05:23:26.021 [SYS:INFO] Package Ver : (null)
2022-10-07 05:23:26.021 [SYS:INFO] mbedTLS Ver : 2.28.0
2022-10-07 05:23:26.021 [SYS:INFO] proto EUI   : 0:fc4b:bcbc:4b90       (/sys/class/net/eth0/address)
2022-10-07 05:23:26.021 [SYS:INFO] prefix EUI  : ::1    (builtin)
2022-10-07 05:23:26.021 [SYS:INFO] Station EUI : fc4b:bcff:febc:4b90
2022-10-07 05:23:26.021 [SYS:INFO] Station home: ./     (builtin)
2022-10-07 05:23:26.021 [SYS:INFO] Station temp: /var/tmp/      (builtin)
2022-10-07 05:23:26.021 [SYS:WARN] Station in NO-CUPS mode
2022-10-07 05:23:26.225 [TCE:INFO] Starting TC engine
2022-10-07 05:23:26.230 [AIO:INFO] ./tc.trust:
cert. version     : 3
serial number     : 82:10:CF:B0:D2:40:E3:59:44:63:E0:BB:63:82:8B:00
issuer name       : C=US, O=Internet Security Research Group, CN=ISRG Root X1
subject name      : C=US, O=Internet Security Research Group, CN=ISRG Root X1
issued  on        : 2015-06-04 11:04:38
expires on        : 2035-06-04 11:04:38
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=true
key usage         : Key Cert Sign, CRL Sig2022-10-07 05:23:26.231 [TCE:INFO] Connecting to INFOS: wss://eu1.cloud.thethings.network:8887
2022-10-07 05:23:27.628 [TCE:INFO] Infos: fc4b:bcff:febc:4b90 muxs-::0 wss://eu1.cloud.thethings.network:8887/traffic/eui-FC4BBCFFFEBC4B90
2022-10-07 05:23:27.628 [AIO:DEBU] [3] ws_close reason=1000
2022-10-07 05:23:27.628 [AIO:ERRO] Recv failed: SSL - The peer notified us that the connection is going to be closed
2022-10-07 05:23:27.628 [AIO:DEBU] [3] WS connection shutdown...
2022-10-07 05:23:27.632 [AIO:INFO] ./tc.trust:
cert. version     : 3
serial number     : 82:10:CF:B0:D2:40:E3:59:44:63:E0:BB:63:82:8B:00
issuer name       : C=US, O=Internet Security Research Group, CN=ISRG Root X1
subject name      : C=US, O=Internet Security Research Group, CN=ISRG Root X1
issued  on        : 2015-06-04 11:04:38
expires on        : 2035-06-04 11:04:38
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=true
key usage         : Key Cert Sign, CRL Sig2022-10-07 05:23:27.632 [TCE:VERB] Connecting to MUXS...
2022-10-07 05:23:28.929 [TCE:VERB] Connected to MUXS.
2022-10-07 05:23:29.140 [S2E:WARN] Unrecognized region: IN865 - ignored
2022-10-07 05:23:29.041 [SYS:VERB] rinit.sh: Forked, waiting...
2022-10-07 05:23:29.042 [SYS:DEBU] execvp argv[0]: </bin/bash>
2022-10-07 05:23:29.043 [SYS:DEBU]        argv[1]: <rinit.sh>
2022-10-07 05:23:29.043 [SYS:DEBU]        argv[2]: <rinit.sh>
2022-10-07 05:23:29.043 [SYS:DEBU]        argv[3]: </dev/spidev0.0>
2022-10-07 05:23:29.416 [SYS:INFO] Process rinit.sh (pid=2392) completed
2022-10-07 05:23:29.416 [RAL:INFO] Lora gateway library version: Version: 2.1.0;
2022-10-07 05:23:29.457 [RAL:INFO] [LGW sx1302] full_duplex=0 clksrc=0 lorawan_public=1
2022-10-07 05:23:29.457 [RAL:DEBU] SX130x txlut table (16 entries)
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  0:  rf_power=12 pa_gain=0 pwr_idx=15
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  1:  rf_power=13 pa_gain=0 pwr_idx=16
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  2:  rf_power=14 pa_gain=0 pwr_idx=17
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  3:  rf_power=15 pa_gain=0 pwr_idx=19
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  4:  rf_power=16 pa_gain=0 pwr_idx=20
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  5:  rf_power=17 pa_gain=0 pwr_idx=22
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  6:  rf_power=18 pa_gain=1 pwr_idx=1
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  7:  rf_power=19 pa_gain=1 pwr_idx=2
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  8:  rf_power=20 pa_gain=1 pwr_idx=3
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut  9:  rf_power=21 pa_gain=1 pwr_idx=4
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut 10:  rf_power=22 pa_gain=1 pwr_idx=5
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut 11:  rf_power=23 pa_gain=1 pwr_idx=6
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut 12:  rf_power=24 pa_gain=1 pwr_idx=7
2022-10-07 05:23:29.457 [RAL:INFO] SX1302 txlut 13:  rf_power=25 pa_gain=1 pwr_idx=9
2022-10-07 05:23:29.458 [RAL:INFO] SX1302 txlut 14:  rf_power=26 pa_gain=1 pwr_idx=11
2022-10-07 05:23:29.458 [RAL:INFO] SX1302 txlut 15:  rf_power=27 pa_gain=1 pwr_idx=14
2022-10-07 05:23:29.458 [RAL:INFO]  RX/TX RF0:    865.2MHz rssi_offset=-215.4 type=5 rssi_tcomp=0.000 0.000 20.410 2162.560 0.000
2022-10-07 05:23:29.458 [RAL:INFO]  RX    RF1:  866.385MHz rssi_offset=-215.4 type=5 rssi_tcomp=0.000 0.000 20.410 2162.560 0.000
2022-10-07 05:23:29.458 [RAL:INFO]  [mSF]   0: 865.0625MHz rf=0 freq=-137.5 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   1: 865.4025MHz rf=0 freq=+202.5 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   2:  865.985MHz rf=1 freq=-400.0 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   3: 865.2325MHz rf=0 freq= +32.5 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   4:  866.185MHz rf=1 freq=-200.0 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   5:  866.385MHz rf=1 freq=  +0.0 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   6:  866.585MHz rf=1 freq=+200.0 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  [mSF]   7:  866.785MHz rf=1 freq=+400.0 datarate=0
2022-10-07 05:23:29.459 [RAL:INFO]  channel 8 disabled
2022-10-07 05:23:29.459 [RAL:INFO]  channel 9 disabled
2022-10-07 05:23:29.459 [RAL:INFO] Station device: spi:/dev/spidev0.0 (PPS capture disabled)
2022-10-07 05:23:29.459 [HAL:INFO] [lgw_com_open:84] Opening SPI communication interface
2022-10-07 05:23:29.460 [HAL:INFO] [lgw_spi_open:88] Setting SPI speed to 2000000
2022-10-07 05:23:29.460 [HAL:INFO] [lgw_connect:1192] chip version is 0x12 (v1.2)
2022-10-07 05:23:31.678 [HAL:INFO] [timestamp_counter_mode:431] using legacy timestamp
2022-10-07 05:23:31.862 [HAL:ERRO] [lgw_start:1105] failed to open I2C for temperature sensor on port 0x39
2022-10-07 05:23:31.862 [RAL:ERRO] Concentrator start failed: lgw_start
2022-10-07 05:23:31.862 [RAL:ERRO] ral_config failed with status 0x08
2022-10-07 05:23:31.862 [any:ERRO] Closing connection to muxs - error in s2e_onMsg
2022-10-07 05:23:31.862 [AIO:DEBU] [3] ws_close reason=1000
2022-10-07 05:23:31.863 [AIO:DEBU] Echoing close - reason=1000
2022-10-07 05:23:32.065 [AIO:DEBU] [3|WS] Server sent close: reason=1000
2022-10-07 05:23:32.065 [AIO:DEBU] [3] WS connection shutdown...
2022-10-07 05:23:32.066 [TCE:VERB] Connection to MUXS closed in state -1
2022-10-07 05:23:32.066 [TCE:INFO] INFOS reconnect backoff 10s (retry 1)
2022-10-07 05:23:42.070 [AIO:INFO] ./tc.trust:
cert. version     : 3
serial number     : 82:10:CF:B0:D2:40:E3:59:44:63:E0:BB:63:82:8B:00
issuer name       : C=US, O=Internet Security Research Group, CN=ISRG Root X1
subject name      : C=US, O=Internet Security Research Group, CN=ISRG Root X1
issued  on        : 2015-06-04 11:04:38
expires on        : 2035-06-04 11:04:38
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=true
key usage         : Key Cert Sign, CRL Sig2022-10-07 05:23:42.070 [TCE:INFO] Connecting to INFOS: wss://eu1.cloud.thethings.network:8887
2022-10-07 05:23:43.488 [TCE:INFO] Infos: fc4b:bcff:febc:4b90 muxs-::0 wss://eu1.cloud.thethings.network:8887/traffic/eui-FC4BBCFFFEBC4B90
2022-10-07 05:23:43.488 [AIO:DEBU] [3] ws_close reason=1000
2022-10-07 05:23:43.488 [AIO:ERRO] Recv failed: SSL - The peer notified us that the connection is going to be closed
2022-10-07 05:23:43.489 [AIO:DEBU] [3] WS connection shutdown...
2022-10-07 05:23:43.492 [AIO:INFO] ./tc.trust:

Please suggest me for this.

beitler commented 1 year ago

Apparently RAK5146 requires some breaking changes to the corecell HAL. Please have a look at this project which maintains some compatibility code for RAK based gateway.

Nileshbhavsar commented 1 year ago

Hello sir,

Till date my gateway working fine but suddenly start throwing this line in log. Repeated excessive clock drifts between MCU/SX130X#0 (15 retries): -996071.3ppm (threshold 100.0ppm)

Please check this because right now gateway is not working properly due to this.

beitler commented 1 year ago

Hi @Nileshbhavsar,

this means that the clock on your host system experienced a discontinuity. Basics Station keeps a close eye on the system clock in order to ensure that jobs are scheduled in time. However, if the clock is jumping (e.g. due to misconfiguration of NTP) this causes problems in any real-time system. Best short term solution is probably to restart the process. Do you know how NTP is configured on your host? Could you disable NTP and see if this error still appears?

Nileshbhavsar commented 1 year ago

Hello Sir,

Yes still facing problem even my clock is working properly and NTP sync is disabled.

root@rak-gateway:/opt/ttn-station# timedatectl
               Local time: Thu 2022-10-20 10:15:47 IST
           Universal time: Thu 2022-10-20 04:45:47 UTC
                 RTC time: Thu 2022-10-20 04:45:47
                Time zone: Asia/Kolkata (IST, +0530)
System clock synchronized: no
              NTP service: inactive
          RTC in local TZ: no

Still same error log occured.

root@rak-gateway:/opt/ttn-station# sudo sh start.sh
2022-10-20 04:44:22.455 [SYS:INFO] Logging     : stderr (maxsize=10000000, rotate=3)
2022-10-20 04:44:22.456 [SYS:INFO] Station Ver : 2.0.6(rpi/std) 2022-10-20 04:42:01
2022-10-20 04:44:22.457 [SYS:INFO] Package Ver : (null)
2022-10-20 04:44:22.458 [SYS:INFO] mbedTLS Ver : 2.28.0
2022-10-20 04:44:22.458 [SYS:INFO] proto EUI   : 0:fc4b:bcbc:4a8c       (/sys/class/net/eth0/address)
2022-10-20 04:44:22.459 [SYS:INFO] prefix EUI  : ::1    (builtin)
2022-10-20 04:44:22.460 [SYS:INFO] Station EUI : fc4b:bcff:febc:4a8c
2022-10-20 04:44:22.461 [SYS:INFO] Station home: ./     (builtin)
2022-10-20 04:44:22.462 [SYS:INFO] Station temp: /var/tmp/      (builtin)
2022-10-20 04:44:22.462 [SYS:WARN] Station in NO-CUPS mode
2022-10-20 04:44:22.666 [TCE:INFO] Starting TC engine
2022-10-20 04:44:22.672 [AIO:INFO] ./tc.trust:
cert. version     : 3
serial number     : 82:10:CF:B0:D2:40:E3:59:44:63:E0:BB:63:82:8B:00
issuer name       : C=US, O=Internet Security Research Group, CN=ISRG Root X1
subject name      : C=US, O=Internet Security Research Group, CN=ISRG Root X1
issued  on        : 2015-06-04 11:04:38
expires on        : 2035-06-04 11:04:38
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=true
key usage         : Key Cert Sign, CRL Sig2022-10-20 04:44:22.673 [TCE:INFO] Connecting to INFOS: wss://eu1.cloud.thethings.network:8887
2022-10-20 04:44:24.181 [TCE:INFO] Infos: fc4b:bcff:febc:4a8c muxs-::0 wss://eu1.cloud.thethings.network:8887/traffic/eui-FC4BBCFFFEBC4A8C
2022-10-20 04:44:24.181 [AIO:DEBU] [3] ws_close reason=1000
2022-10-20 04:44:24.182 [AIO:ERRO] Recv failed: SSL - The peer notified us that the connection is going to be closed
2022-10-20 04:44:24.182 [AIO:DEBU] [3] WS connection shutdown...
2022-10-20 04:44:24.186 [AIO:INFO] ./tc.trust:
cert. version     : 3
serial number     : 82:10:CF:B0:D2:40:E3:59:44:63:E0:BB:63:82:8B:00
issuer name       : C=US, O=Internet Security Research Group, CN=ISRG Root X1
subject name      : C=US, O=Internet Security Research Group, CN=ISRG Root X1
issued  on        : 2015-06-04 11:04:38
expires on        : 2035-06-04 11:04:38
signed using      : RSA with SHA-256
RSA key size      : 4096 bits
basic constraints : CA=true
key usage         : Key Cert Sign, CRL Sig2022-10-20 04:44:24.186 [TCE:VERB] Connecting to MUXS...
2022-10-20 04:44:25.543 [TCE:VERB] Connected to MUXS.
2022-10-20 04:44:25.769 [S2E:WARN] Unrecognized region: IN865 - ignored
2022-10-20 04:44:24.414 [SYS:VERB] /opt/ttn-station/reset_gw.sh: Forked, waiting...
2022-10-20 04:44:24.415 [SYS:DEBU] execvp argv[0]: </bin/bash>
2022-10-20 04:44:24.416 [SYS:DEBU]        argv[1]: </opt/ttn-station/reset_gw.sh>
2022-10-20 04:44:24.416 [SYS:DEBU]        argv[2]: </opt/ttn-station/reset_gw.sh>
2022-10-20 04:44:24.416 [SYS:DEBU]        argv[3]: </dev/spidev0.0>
2022-10-20 04:44:24.778 [SYS:INFO] Process /opt/ttn-station/reset_gw.sh (pid=3097) completed
2022-10-20 04:44:24.778 [RAL:INFO] Lora gateway library version: Version: 5.0.1;
2022-10-20 04:44:24.819 [RAL:INFO] [LGW lgw1] clksrc=1 lorawan_public=1
2022-10-20 04:44:24.820 [RAL:INFO]  RX/TX RF0:    865.2MHz rssi_offset=-166.0 type=2 tx_notch_freq=0
2022-10-20 04:44:24.820 [RAL:INFO]  RX    RF1:  866.385MHz rssi_offset=-166.0 type=2 tx_notch_freq=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   0: 865.0625MHz rf=0 freq=-137.5 datarate=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   1: 865.4025MHz rf=0 freq=+202.5 datarate=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   2:  865.985MHz rf=1 freq=-400.0 datarate=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   3: 865.2325MHz rf=0 freq= +32.5 datarate=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   4:  866.185MHz rf=1 freq=-200.0 datarate=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   5:  866.385MHz rf=1 freq=  +0.0 datarate=0
2022-10-20 04:44:24.820 [RAL:INFO]  [mSF]   6:  866.585MHz rf=1 freq=+200.0 datarate=0
2022-10-20 04:44:24.821 [RAL:INFO]  [mSF]   7:  866.785MHz rf=1 freq=+400.0 datarate=0
2022-10-20 04:44:24.821 [RAL:INFO]  channel 8 disabled
2022-10-20 04:44:24.821 [RAL:INFO]  channel 9 disabled
2022-10-20 04:44:24.821 [RAL:INFO] SX130x LBT not enabled
2022-10-20 04:44:24.821 [RAL:INFO] Station device: /dev/spidev0.0 (PPS capture enabled)
2022-10-20 04:44:24.821 [HAL:INFO] [lgw_spi_open:101] Setting SPI speed to 2000000
2022-10-20 04:44:24.821 [HAL:INFO] [lgw_spi_open:135] Note: SPI port opened and configured ok
2022-10-20 04:44:27.892 [RAL:INFO] Concentrator started (3s70ms)
2022-10-20 04:44:27.892 [S2E:INFO] Configuring for region: IN865 -- 865.0MHz..867.0MHz
2022-10-20 04:44:27.892 [S2E:INFO]   DR0  SF12/BW125
2022-10-20 04:44:27.892 [S2E:INFO]   DR1  SF11/BW125
2022-10-20 04:44:27.892 [S2E:INFO]   DR2  SF10/BW125
2022-10-20 04:44:27.892 [S2E:INFO]   DR3  SF9/BW125
2022-10-20 04:44:27.892 [S2E:INFO]   DR4  SF8/BW125
2022-10-20 04:44:27.892 [S2E:INFO]   DR5  SF7/BW125
2022-10-20 04:44:27.892 [S2E:INFO]   DR6  FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR7  FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR8  FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR9  FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR10 FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR11 FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR12 FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR13 FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR14 FSK
2022-10-20 04:44:27.892 [S2E:INFO]   DR15 FSK
2022-10-20 04:44:27.892 [S2E:INFO]   TX power: 14.0 dBm EIRP
2022-10-20 04:44:27.892 [S2E:INFO]   JoinEui list: 0 entries
2022-10-20 04:44:27.892 [S2E:INFO]   NetID filter: FFFFFFFF-FFFFFFFF-FFFFFFFF-FFFFFFFF
2022-10-20 04:44:27.892 [S2E:INFO]   Dev/test settings: nocca=1 nodc=1 nodwell=1
2022-10-20 04:44:27.892 [S2E:INFO] Beaconing every 2m8s on 866.5MHz(1) @ DR4 (frame layout 1/7/19)
2022-10-20 04:44:27.892 [S2E:INFO] Beaconing suspend - missing GPS data: time
2022-10-20 04:44:51.002 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (3 retries): -997991.8ppm (threshold 100.0ppm)
2022-10-20 04:44:54.156 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (6 retries): -996484.9ppm (threshold 100.0ppm)
2022-10-20 04:44:57.308 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (9 retries): -994978.2ppm (threshold 100.0ppm)
2022-10-20 04:44:59.410 [SYN:INFO] MCU/SX130X drift stats: min: -33.3ppm  q50: -994476.0ppm  q80: -997489.7ppm  max: -998996.0ppm - threshold q90: -998493.9ppm
2022-10-20 04:44:59.410 [SYN:INFO] Mean MCU drift vs SX130X#0: -548083.7ppm
2022-10-20 04:45:19.643 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (12 retries): -993471.5ppm (threshold 100.0ppm)
2022-10-20 04:45:22.795 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (15 retries): -991965.0ppm (threshold 100.0ppm)
2022-10-20 04:45:25.948 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (18 retries): -990458.3ppm (threshold 100.0ppm)
2022-10-20 04:45:28.050 [SYN:INFO] Time sync qualities: min=80 q90=126 max=674 (previous q90=2147483647)
2022-10-20 04:45:29.101 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (21 retries): -988951.5ppm (threshold 100.0ppm)
2022-10-20 04:45:32.254 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (24 retries): -987444.8ppm (threshold 100.0ppm)
2022-10-20 04:45:35.406 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (27 retries): -985938.2ppm (threshold 100.0ppm)
2022-10-20 04:45:38.559 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (30 retries): -984431.6ppm (threshold 100.0ppm)
2022-10-20 04:45:39.610 [SYN:VERB] Time sync rejected: quality=164 threshold=126
2022-10-20 04:45:41.711 [SYN:INFO] MCU/SX130X drift stats: min: -982925.0ppm  q50: -988951.5ppm  q80: -991965.0ppm  max: -993471.5ppm - threshold q90: -992969.3ppm
2022-10-20 04:45:41.712 [SYN:INFO] Mean MCU drift vs SX130X#0: -988650.2ppm
2022-10-20 04:46:06.670 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (33 retries): -981920.5ppm (threshold 100.0ppm)
2022-10-20 04:46:09.823 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (36 retries): -980413.9ppm (threshold 100.0ppm)
2022-10-20 04:46:12.975 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (39 retries): -978907.3ppm (threshold 100.0ppm)
2022-10-20 04:46:16.128 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (42 retries): -977400.7ppm (threshold 100.0ppm)
2022-10-20 04:46:19.280 [SYN:WARN] Repeated excessive clock drifts between MCU/SX130X#0 (45 retries): -975894.2ppm (threshold 100.0ppm)