We were having issues with the time sync on the regular LoRa Packet Forwarder an…d figured that we'd try this one instead.
The setup is as follows:
The gateway is custom and based on a TI SOC. It is running ubuntu over a kernel by TI. This board is an expansion for an existing base gateway, so the I/O was limited. Because of that an FTDI usb-serial adapter is used to run both the SPI via MPSSE and the GPS serial port. By modifying libFTDI and libMPSSE to allow for microframes the SPI latency is fairly low, with several complete exchanges occurring within a millisecond. libloragateway was modified so that all the SPI HAL functions instead call on the MPSSE functions. The SPI communication tests from libloragw seem to work just fine.
libloragw is taken from sx1302_hal 1.0.5 and further patched with the corecell patch from lgw1302. I also increased DFLT_TX_AIM_GAP to 50 ms in order to reduce the risk of latency being an issue.
Basic Station connects to a chirpstack server on another device using chirpstack-gateway-bridge with authorization disabled. The following is the station.conf:
```
{
/* If slave-X.conf present this acts as default settings */
"SX1302_conf": { /* Actual channel plan is controlled by server */
"device": "/dev/spidev0.0",
"lorawan_public": true, /* is default */
"clksrc": 0, /* radio_0 provides clock to concentrator */
"full_duplex": false,
"pps": true,
"radio_0": {
/* freq/enable provided by LNS - only HW specific settings listed here */
"type": "SX1250",
"rssi_offset": -215.4,
"rssi_tcomp": {"coeff_a": 0, "coeff_b": 0, "coeff_c": 20.41, "coeff_d": 2162.56, "coeff_e": 0},
"tx_enable": true,
"antenna_gain": 0, /* antenna gain, in dBi */
"tx_gain_lut":[
{"rf_power": 12, "pa_gain": 0, "pwr_idx": 15},
{"rf_power": 13, "pa_gain": 0, "pwr_idx": 16},
{"rf_power": 14, "pa_gain": 0, "pwr_idx": 17},
{"rf_power": 15, "pa_gain": 0, "pwr_idx": 19},
{"rf_power": 16, "pa_gain": 0, "pwr_idx": 20},
{"rf_power": 17, "pa_gain": 0, "pwr_idx": 22},
{"rf_power": 18, "pa_gain": 1, "pwr_idx": 1},
{"rf_power": 19, "pa_gain": 1, "pwr_idx": 2},
{"rf_power": 20, "pa_gain": 1, "pwr_idx": 3},
{"rf_power": 21, "pa_gain": 1, "pwr_idx": 4},
{"rf_power": 22, "pa_gain": 1, "pwr_idx": 5},
{"rf_power": 23, "pa_gain": 1, "pwr_idx": 6},
{"rf_power": 24, "pa_gain": 1, "pwr_idx": 7},
{"rf_power": 25, "pa_gain": 1, "pwr_idx": 9},
{"rf_power": 26, "pa_gain": 1, "pwr_idx": 11},
{"rf_power": 27, "pa_gain": 1, "pwr_idx": 14}
]
},
"radio_1": {
"type": "SX1250",
"rssi_offset": -215.4,
"rssi_tcomp": {"coeff_a": 0, "coeff_b": 0, "coeff_c": 20.41, "coeff_d": 2162.56, "coeff_e": 0},
"tx_enable": false
}
/* chan_multiSF_X, chan_Lora_std, chan_FSK provided by LNS */
},
"station_conf": {
"radio_init": "rinit.sh",
"RADIO_INIT_WAIT": "5s",
"RX_POLL_INTV": "10ms",
"TC_TIMEOUT": "360s",
"log_file": "stderr", /* "station.log" */
"log_level": "DEBUG", /* XDEBUG,DEBUG,VERBOSE,INFO,NOTICE,WARNING,ERROR,CRITICAL */
"log_size": 10000000,
"log_rotate": 3,
"gps": "/dev/ttyUSB1",
"pps": "gps"
}
}
```
It seems to work for a while, but constantly prints about time sync being rejected. Here is a small sample of what it prints:
```
2021-11-02 12:00:46.184 [SYN:INFO] MCU/SX130X drift stats: min: +4.3ppm q50: +74.5ppm q80: -99.8ppm max: +222.7ppm - threshold q90: -107.7ppm
2021-11-02 12:00:46.185 [SYN:INFO] Mean MCU drift vs SX130X#0: 23.0ppm
2021-11-02 12:00:46.941 [S2E:VERB] RX 868.3MHz DR5 SF7/BW125 snr=14.0 rssi=-62 xtime=0x82000009C5E328 - updf mhdr=40 DevAddr=01AEB637 FCtrl=90 FCnt=5286 FOpts=[] 02AD16CC..E12E mic=952774489 (41 bytes)
2021-11-02 12:00:48.294 [SYN:VERB] Time sync rejected: quality=3187 threshold=2431
2021-11-02 12:00:51.257 [S2E:VERB] RX 867.9MHz DR5 SF7/BW125 snr=13.5 rssi=-79 xtime=0x8200000A07D603 - updf mhdr=40 DevAddr=00E191B1 FCtrl=90 FCnt=5256 FOpts=[] 02613009..F1B0 mic=-199049753 (31 bytes)
2021-11-02 12:00:52.854 [S2E:VERB] RX 868.1MHz DR5 SF7/BW125 snr=14.0 rssi=-78 xtime=0x8200000A205BFC - updf mhdr=40 DevAddr=01E916B1 FCtrl=90 FCnt=5267 FOpts=[] 021AD7F4..48AA mic=-657448789 (31 bytes)
2021-11-02 12:00:53.564 [SYN:INFO] Time sync qualities: min=665 q90=3045 max=3469 (previous q90=2431)
2021-11-02 12:00:53.585 [S2E:VERB] RX 867.9MHz DR5 SF7/BW125 snr=13.5 rssi=-79 xtime=0x8200000A2B6EDA - updf mhdr=40 DevAddr=00E191B1 FCtrl=90 FCnt=5256 FOpts=[] 02613009..F1B0 mic=-199049753 (31 bytes)
2021-11-02 12:00:55.914 [S2E:VERB] RX 867.5MHz DR5 SF7/BW125 snr=10.2 rssi=-78 xtime=0x8200000A4F07BC - updf mhdr=40 DevAddr=00E191B1 FCtrl=90 FCnt=5256 FOpts=[] 02613009..F1B0 mic=-199049753 (31 bytes)
2021-11-02 12:00:59.890 [SYN:VERB] Time sync rejected: quality=3306 threshold=3045
2021-11-02 12:01:04.104 [SYN:VERB] Time sync rejected: quality=3058 threshold=3045
2021-11-02 12:01:06.214 [SYN:VERB] Time sync rejected: quality=3495 threshold=3045
2021-11-02 12:01:15.483 [S2E:VERB] RX 867.7MHz DR0 SF12/BW125 snr=11.2 rssi=-66 xtime=0x8200000B797B2F - updf mhdr=80 DevAddr=008160AE FCtrl=80 FCnt=3466 FOpts=[] 0167C2BC mic=-568887544 (16 bytes)
2021-11-02 12:01:17.807 [SYN:VERB] Time sync rejected: quality=3350 threshold=3045
2021-11-02 12:01:21.283 [S2E:VERB] RX 868.5MHz DR0 SF12/BW125 snr=8.0 rssi=-69 xtime=0x8200000BD223FC - updf mhdr=80 DevAddr=008160AE FCtrl=80 FCnt=3466 FOpts=[] 0167C2BC mic=-568887544 (16 bytes)
2021-11-02 12:01:24.138 [SYN:VERB] Time sync rejected: quality=3774 threshold=3045
2021-11-02 12:01:35.403 [S2E:VERB] RX 868.5MHz DR5 SF7/BW125 snr=10.2 rssi=-46 xtime=0x8200000CA999DF - updf mhdr=80 DevAddr=001B82D8 FCtrl=80 FCnt=55963 FOpts=[] 02E9512E..69F1 mic=1208999552 (22 bytes)
2021-11-02 12:01:35.730 [SYN:VERB] Time sync rejected: quality=3695 threshold=3045
2021-11-02 12:01:38.894 [SYN:INFO] MCU/SX130X drift stats: min: -1.9ppm q50: +34.2ppm q80: +102.2ppm max: +139.7ppm - threshold q90: +138.2ppm
2021-11-02 12:01:38.894 [SYN:INFO] Mean MCU drift vs SX130X#0: 34.5ppm
```
After about half an hour it seems to obtain the first PPS pulse (although I can see that the PPS pin on the RAK2287 is pulsing every second on a scope). Then it tries to time sync with the network server with what looks like completely incorrect times:
```
2021-11-02 12:33:55.742 [SYN:INFO] First PPS pulse acquired
2021-11-02 12:33:55.742 [SYN:INFO] Obtained initial PPS offset (384393) - starting timesync with LNS
2021-11-02 12:33:55.868 [SYN:INFO] Time sync: ustime=0xDC505712 utc=0x5CFCD81C37289 gpsOffset=0x0 ppsOffset=384393 syncQual=657
2021-11-02 12:33:55.868 [SYN:INFO] Time sync: MCU/SX130X#0 ustime=0xDC504B77 xtime=0x82000080519E6E pps_xtime=0x82000100000000
2021-11-02 12:33:55.868 [SYN:INFO] Time sync: Last PPS ustime=0xDC504B77 xtime=0x82000080519E6E pps_ustime=0x15BFEAD09 pps_xtime=0x82000100000000
2021-11-02 12:33:55.868 [SYN:DEBU] Timesync #2 sent to server
2021-11-02 12:33:55.887 [SYN:VERB] Timesync LNS: tx/rx:0xDC4A7A7C..0xDC4AC499 (18ms973us) us/gps:0x0/0x4B06F392AD81B (pps offset=384393) - 0 solutions
2021-11-02 12:33:55.939 [SYN:DEBU] Timesync #3 sent to server
2021-11-02 12:33:55.959 [SYN:VERB] Timesync LNS: tx/rx:0xDC4B90A5..0xDC4BDBEC (19ms271us) us/gps:0x0/0x4B06F392BB229 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.011 [SYN:DEBU] Timesync #4 sent to server
2021-11-02 12:33:56.016 [SYN:VERB] Timesync LNS: tx/rx:0xDC4CA6D1..0xDC4CBDAD (5ms852us) us/gps:0x0/0x4B06F392CC898 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.082 [SYN:DEBU] Timesync #5 sent to server
2021-11-02 12:33:56.097 [SYN:VERB] Timesync LNS: tx/rx:0xDC4DBD71..0xDC4DF9FE (15ms501us) us/gps:0x0/0x4B06F392E0DD8 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.157 [SYN:DEBU] Timesync #6 sent to server
2021-11-02 12:33:56.166 [SYN:VERB] Timesync LNS: tx/rx:0xDC4EE21D..0xDC4F04DB (8ms894us) us/gps:0x0/0x4B06F392F0C84 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.229 [SYN:DEBU] Timesync #7 sent to server
2021-11-02 12:33:56.245 [SYN:VERB] Timesync LNS: tx/rx:0xDC4FFA43..0xDC50398B (16ms200us) us/gps:0x0/0x4B06F39303C81 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.300 [SYN:DEBU] Timesync #8 sent to server
2021-11-02 12:33:56.322 [SYN:VERB] Timesync LNS: tx/rx:0xDC511126..0xDC5168CE (22ms440us) us/gps:0x0/0x4B06F393134D0 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.371 [SYN:DEBU] Timesync #9 sent to server
2021-11-02 12:33:56.388 [SYN:VERB] Timesync LNS: tx/rx:0xDC52281B..0xDC526B1F (17ms156us) us/gps:0x0/0x4B06F39327F70 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.443 [SYN:DEBU] Timesync #10 sent to server
2021-11-02 12:33:56.473 [SYN:VERB] Timesync LNS: tx/rx:0xDC533E73..0xDC53B5EB (30ms584us) us/gps:0x0/0x4B06F3933BC55 (pps offset=384393) - 0 solutions
2021-11-02 12:33:56.514 [SYN:DEBU] Timesync #11 sent to server
2021-11-02 12:33:56.523 [SYN:VERB] Timesync LNS: tx/rx:0xDC545536..0xDC54786F (9ms17us) us/gps:0x0/0x4B06F3934793D (pps offset=384393) - 0 solutions
2021-11-02 12:33:58.665 [SYN:ERRO] No PPS pulse for ~-2138 secs
2021-11-02 12:34:00.412 [SYN:VERB] Time sync rejected: quality=2042 threshold=1624
```
Time since last PPS seems to be negative, so something is off.
Now, I realize this is not a supported gateway and the interface we're using is not ideal. But if anyone has an idea about what the issue could be or where to start looking that would be greatly appreciated.