search

lorabasics / basicstation

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

basicstation fails to connect to Chirpstack gateway bridge using rak2245 on orangepi zero #60

Closed dolfandringa closed 4 years ago

dolfandringa commented 4 years ago

I am trying to get basicstation to run on my orangepi zero with a rak2245 concentrator, with chirpstack-gateway-bridge but I am failing sofar. I managed to get it to work with the semtech udp packet forwarder quite easily. The only thing I needed to do there was change the spidev to /dev/spidev1.0 (spidev0 is not available) and change the reset pin to GPIO1 instead of 17 for the rpi.

With basicstation I get an error that the websocket connection is closed, and that it failed to lgw_start /dev/spidev1.0. I am wondering if I am having an SPIDEV issue, or a LNS/websocket issue with chirpstack.

I tried resetting it with the reset_lgw.sh start 1 script (using the -i parameter) but that didn't help either. I am using the US915 band and setup sub-bad 1 (903.9-905.3MHz) as the multi_sf frequencies and didn't specify an tls certificates on the chirpstack-gateway-bridge side. 

020-05-05 10:04:00.942 [SYS:INFO] Logging     : ./station.log (maxsize=10000000, rotate=3)
2020-05-05 10:04:00.942 [SYS:INFO] Station Ver : 2.0.3(rpi/std) 2020-05-05 09:54:14
2020-05-05 10:04:00.942 [SYS:INFO] Package Ver : (null)
2020-05-05 10:04:00.942 [SYS:INFO] proto EUI   : 242:58ff:fef7:bf4b     (station.conf file routerid.txt)
2020-05-05 10:04:00.942 [SYS:INFO] prefix EUI  : ::1    (builtin)
2020-05-05 10:04:00.943 [SYS:INFO] Station EUI : 242:58ff:fef7:bf4b
2020-05-05 10:04:00.943 [SYS:INFO] Station home: ./     (builtin)
2020-05-05 10:04:00.943 [SYS:INFO] Station temp: /var/tmp/      (builtin)
2020-05-05 10:04:00.943 [SYS:WARN] Station in NO-CUPS mode
2020-05-05 10:04:01.145 [TCE:INFO] Starting TC engine
2020-05-05 10:04:01.147 [TCE:INFO] Connecting to INFOS: ws://127.0.0.1:3001
2020-05-05 10:04:01.149 [TCE:INFO] Infos: 0242:58ff:fef7:bf4b 0242:58ff:fef7:bf4b ws://127.0.0.1:3001/gateway/024258fffef7bf4b
2020-05-05 10:04:01.151 [AIO:ERRO] Recv failed: NET - Connection was reset by peer
2020-05-05 10:04:01.152 [TCE:VERB] Connecting to MUXS...
2020-05-05 10:04:01.157 [TCE:VERB] Connected to MUXS.
2020-05-05 10:04:01.201 [RAL:INFO] Lora gateway library version: Version: 5.0.1;
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 rxrfchain 0: enable=1 freq=904300000 rssi_offset=-166.000000 type=2 tx_enable=1 tx_notch_freq=0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 rxrfchain 1: enable=1 freq=905300000 rssi_offset=-166.000000 type=2 tx_enable=1 tx_notch_freq=0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  0: enable=1 rf_chain=0 freq=-400000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  1: enable=1 rf_chain=0 freq=-200000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  2: enable=1 rf_chain=0 freq=0 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  3: enable=1 rf_chain=0 freq=200000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  4: enable=1 rf_chain=0 freq=400000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  5: enable=1 rf_chain=1 freq=-400000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  6: enable=1 rf_chain=1 freq=-200000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.201 [RAL:VERB] SX1301 ifchain  7: enable=1 rf_chain=1 freq=0 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.202 [RAL:VERB] SX1301 ifchain  8: enable=1 rf_chain=0 freq=300000 bandwidth=1 datarate=4 sync_word=0/0
2020-05-05 10:04:01.202 [RAL:VERB] SX1301 ifchain  9: enabI am wondering if I am having an SPIDEV issue, or a LNS/websocket issue with chirpstack.le=0 rf_chain=0 freq=0 bandwidth=0 datarate=0 sync_word=0/0
2020-05-05 10:04:01.202 [RAL:VERB] SX1301 LBT not enabled
2020-05-05 10:04:01.202 [RAL:INFO] Station device: /dev/spidev1.0 (PPS capture disabled)
2020-05-05 10:04:01.202 [RAL:ERRO] lgw_start failed: /dev/spidev1.0
2020-05-05 10:04:01.202 [any:ERRO] Closing connection to muxs - error in s2e_onMsg
2020-05-05 10:04:01.203 [TCE:VERB] Connection to MUXS closed in state -1
2020-05-05 10:04:01.203 [TCE:INFO] INFOS reconnect backoff 10s (retry 1)

This is my station.conf:

{
        "station_conf": {
                "routerid": "routerid.txt",
                "log_file": "station.log",
                "log_level": "VERBOSE",
                "log_size": 10e6,
                "log_rotate": 3,
                 "device": "/dev/spidev1.0"
        },
        "SX1301_conf": {
                "lorawan_public": true,
                 "clksrc": 1,
                 "device": "/dev/spidev1.0",
                "radio_0": {
                        "type": "SX1257",
                        "rssi_offset": -166.0,
                        "tx_enable": true,
                        "antenna_gain": 0
                },
                "radio_1": {
                        "type": "SX1257",
                        "rssi_offset": -166.0,
                        "tx_enable": true,
                        "antenna_gain": 0
                }
        }
}

On the chirpstack side I do see basicstation trying to connect, send the version info and chirpstack responding with a router_config message:

chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: router-info request received" gateway_id=024258fffef7bf4b remote_addr="127.0.0.1:37906" router_uri="ws://127.0.0.1:3001/gateway/024258fffef7bf4b"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: router-info request received" gateway_id=024258fffef7bf4b remote_addr="127.0.0.1:37906" router_uri="ws://127.0.0.1:3001/gateway/024258fffef7bf4b"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: gateway connected" gateway_id=024258fffef7bf4b remote_addr="127.0.0.1:37908"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="integration/mqtt: set gateway subscription called" gateway_id=024258fffef7bf4b subscribe=true
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: gateway connected" gateway_id=024258fffef7bf4b remote_addr="127.0.0.1:37908"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="integration/mqtt: subscribing to topic" qos=0 topic="gateway/024258fffef7bf4b/command/#"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="backend/basicstation: message received" gateway_id=024258fffef7bf4b message="{\"msgtype\":\"version\",\"station\":\"2.0.3(rpi/std)\",\"firmware\":null,\"package\":null,\"model\":\"rpi\",\"protocol\":2,\"features\":\"rmtsh\"}"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="integration/mqtt: set gateway subscription called" gateway_id=024258fffef7bf4b subscribe=true
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: gateway version received" firmware= gateway_id=024258fffef7bf4b model=rpi package= protocol=2 station="2.0.3(rpi/std)"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="sending message to gateway" gateway_id=024258fffef7bf4b message="{\"msgtype\":\"router_config\",\"NetID\":null,\"JoinEui\":null,\"region\":\"US902\",\"hwspec\":\"sx1301/1\",\"freq_range\":[902000000,928000000],\"DRs\":[[10,125,0],[9,125,0],[8,125,0],[7,125,0],[8,500,0],[-1,0,0],[-1,0,0],[-1,0,0],[12,500,1],[11,500,1],[10,500,1],[9,500,1],[8,500,0],[7,500,1],[-1,0,0],[-1,0,0]],\"sx1301_conf\":[{\"radio_0\":{\"enable\":true,\"freq\":904300000},\"radio_1\":{\"enable\":true,\"freq\":905300000},\"chan_FSK\":{\"enable\":false},\"chan_Lora_std\":{\"enable\":true,\"radio\":0,\"if\":300000,\"bandwidth\":500000,\"spread_factor\":8},\"chan_multiSF_0\":{\"enable\":true,\"radio\":0,\"if\":-400000},\"chan_multiSF_1\":{\"enable\":true,\"radio\":0,\"if\":-200000},\"chan_multiSF_2\":{\"enable\":true,\"radio\":0,\"if\":0},\"chan_multiSF_3\":{\"enable\":true,\"radio\":0,\"if\":200000},\"chan_multiSF_4\":{\"enable\":true,\"radio\":0,\"if\":400000},\"chan_multiSF_5\":{\"enable\":true,\"radio\":1,\"if\":-400000},\"chan_multiSF_6\":{\"enable\":true,\"radio\":1,\"if\":-200000},\"chan_multiSF_7\":{\"enable\":true,\"radio\":1,\"if\":0}}]}"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="integration/mqtt: subscribing to topic" qos=0 topic="gateway/024258fffef7bf4b/command/#"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: router-config message sent to gateway" gateway_id=024258fffef7bf4b
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="backend/basicstation: message received" gateway_id=024258fffef7bf4b message="{\"msgtype\":\"version\",\"station\":\"2.0.3(rpi/std)\",\"firmware\":null,\"package\":null,\"model\":\"rpi\",\"protocol\":2,\"features\":\"rmtsh\"}"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: gateway version received" firmware= gateway_id=024258fffef7bf4b model=rpi package= protocol=2 station="2.0.3(rpi/std)"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="sending message to gateway" gateway_id=024258fffef7bf4b message="{\"msgtype\":\"router_config\",\"NetID\":null,\"JoinEui\":null,\"region\":\"US902\",\"hwspec\":\"sx1301/1\",\"freq_range\":[902000000,928000000],\"DRs\":[[10,125,0],[9,125,0],[8,125,0],[7,125,0],[8,500,0],[-1,0,0],[-1,0,0],[-1,0,0],[12,500,1],[11,500,1],[10,500,1],[9,500,1],[8,500,0],[7,500,1],[-1,0,0],[-1,0,0]],\"sx1301_conf\":[{\"radio_0\":{\"enable\":true,\"freq\":904300000},\"radio_1\":{\"enable\":true,\"freq\":905300000},\"chan_FSK\":{\"enable\":false},\"chan_Lora_std\":{\"enable\":true,\"radio\":0,\"if\":300000,\"bandwidth\":500000,\"spread_factor\":8},\"chan_multiSF_0\":{\"enable\":true,\"radio\":0,\"if\":-400000},\"chan_multiSF_1\":{\"enable\":true,\"radio\":0,\"if\":-200000},\"chan_multiSF_2\":{\"enable\":true,\"radio\":0,\"if\":0},\"chan_multiSF_3\":{\"enable\":true,\"radio\":0,\"if\":200000},\"chan_multiSF_4\":{\"enable\":true,\"radio\":0,\"if\":400000},\"chan_multiSF_5\":{\"enable\":true,\"radio\":1,\"if\":-400000},\"chan_multiSF_6\":{\"enable\":true,\"radio\":1,\"if\":-200000},\"chan_multiSF_7\":{\"enable\":true,\"radio\":1,\"if\":0}}]}"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: router-config message sent to gateway" gateway_id=024258fffef7bf4b
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: gateway disconnected" gateway_id=024258fffef7bf4b remote_addr="127.0.0.1:37908"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="integration/mqtt: set gateway subscription called" gateway_id=024258fffef7bf4b subscribe=false
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="backend/basicstation: gateway disconnected" gateway_id=024258fffef7bf4b remote_addr="127.0.0.1:37908"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=debug msg="integration/mqtt: set gateway subscription called" gateway_id=024258fffef7bf4b subscribe=false
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="integration/mqtt: unsubscribing from topic" topic="gateway/024258fffef7bf4b/command/#"
chirpstack-gateway-bridge[8323]: time="2020-05-05T18:04:01+08:00" level=info msg="integration/mqtt: unsubscribing from topic" topic="gateway/024258fffef7bf4b/command/#"
beitler commented 4 years ago

It looks like the radio is failing to start:

2020-05-05 10:04:01.202 [RAL:ERRO] lgw_start failed: /dev/spidev1.0

lgw_start is a HAL layer function. Reasons for this failure could be many. Most often it is related to an SPI communication problem. Try to build the HAL with DEBUG flags and run again. The DEBUG flags must be set in the library.cfg file inside deps/lgw/platform-$platform.

Note that in the station.conf file you can specify a script to be executed before radio startup (radio_init field). This way you can have the reset_lgw.sh script be called automatically. Read more about this feature in the docu: https://doc.sm.tc/station/conf.html#radio-configuration

tonysmith55 commented 4 years ago

Just checking, have you set the SPI speed in the orangepi to 2MHz as the RAK2245 has internal level shifters to work on either 1.8 volts or 3.3 volts and they limit the SPI port speed to 2MHz. This would certainly prevent the gateway starting.

dolfandringa commented 4 years ago

Thanks for the help @beitler. I will turn on the DEBUG flags and run again. But like I said, the RAK2245 does work fine with the semtech udp lora packet forwarder. So it is definitely someting on the lgw/basicstation side. The SPI speed is set when you start SPI communication, so would be the responsibility of lgw I think.

dolfandringa commented 4 years ago

Ok, I am getting somewhere. It turns out the libloragw version and packet_forwarder that I was using was a slightly modified version by rakk. They use libloragw 5.0.1 as well, but also modify it slightly. First of all, they don't apply the patch that you give for platform linux and platform rpi. I also did a diff between the vanilla libloragw 5.0.1 and the files they supply for the RAKK2445. They changed 2 files for libloragw: library.cfg and loragw_spi_native.c. In library.cfg they added CFG_SPI= native and PLATFOR imst_rpi. And in loragw_spi_native.c the changed the SPI_SPEED to 2000000MHz instead of 8000000. I also changed RADIO_INIT_WAIT in src/s2conf.h to 1000ms because the radio_init reset script was getting killed.

I applied those changes to my libgw for basicstation, and turned the DEBUG flag on in library.cfg. Now I am getting a CALIBRATION FAILURE:

2020-05-06 01:44:28.028 [SYS:INFO] Logging     : stderr (maxsize=10000000, rotate=3)
2020-05-06 01:44:28.028 [SYS:INFO] Station Ver : 2.0.3(rpi/std) 2020-05-06 01:29:59
2020-05-06 01:44:28.028 [SYS:INFO] Package Ver : (null)
2020-05-06 01:44:28.028 [SYS:INFO] proto EUI   : 242:58ff:fef7:bf4b     (station.conf file routerid.txt)
2020-05-06 01:44:28.028 [SYS:INFO] prefix EUI  : ::1    (builtin)
2020-05-06 01:44:28.028 [SYS:INFO] Station EUI : 242:58ff:fef7:bf4b
2020-05-06 01:44:28.028 [SYS:INFO] Station home: ./     (builtin)
2020-05-06 01:44:28.029 [SYS:INFO] Station temp: /var/tmp/      (builtin)
2020-05-06 01:44:28.029 [SYS:WARN] Station in NO-CUPS mode
2020-05-06 01:44:28.231 [TCE:INFO] Starting TC engine
2020-05-06 01:44:28.232 [TCE:INFO] Connecting to INFOS: ws://127.0.0.1:3001
2020-05-06 01:44:28.234 [TCE:INFO] Infos: 0242:58ff:fef7:bf4b 0242:58ff:fef7:bf4b ws://127.0.0.1:3001/gateway/024258fffef7bf4b
2020-05-06 01:44:28.235 [AIO:ERRO] Recv failed: NET - Connection was reset by peer
2020-05-06 01:44:28.236 [TCE:VERB] Connecting to MUXS...
2020-05-06 01:44:28.238 [TCE:VERB] Connected to MUXS.
Accessing concentrator reset pin through GPIO1...
lgw_board_setconf:449: Note: board configuration; lorawan_public:1, clksrc:1
lgw_rxrf_setconf:498: WARNING: NOT A VALID TX NOTCH FILTER FREQUENCY [126000..250000]Hz
lgw_rxrf_setconf:510: Note: rf_chain 0 configuration; en:1 freq:904300000 rssi_offset:-166.000000 radio_type:2 tx_enable:1 tx_notch_freq:0
lgw_rxrf_setconf:498: WARNING: NOT A VALID TX NOTCH FILTER FREQUENCY [126000..250000]Hz
lgw_rxrf_setconf:510: Note: rf_chain 1 configuration; en:1 freq:905300000 rssi_offset:-166.000000 radio_type:2 tx_enable:1 tx_notch_freq:0
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 0 configuration; en:1 freq:-400000 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 1 configuration; en:1 freq:-200000 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 2 configuration; en:1 freq:0 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 3 configuration; en:1 freq:200000 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 4 configuration; en:1 freq:400000 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 5 configuration; en:1 freq:-400000 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 6 configuration; en:1 freq:-200000 SF_mask:0x7e
lgw_rxif_setconf:629: Note: LoRa 'multi' if_chain 7 configuration; en:1 freq:0 SF_mask:0x7e
lgw_rxif_setconf:603: Note: LoRa 'std' if_chain 8 configuration; en:1 freq:300000 bw:1 dr:4
lgw_rxif_setconf:537: Note: if_chain 9 disabled
Note: SPI port opened and configured ok
Note: SPI read success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
lgw_spi_wb:309: BURST WRITE: to trans 8192 # chunk 1024 # transferred 1024
lgw_spi_wb:309: BURST WRITE: to trans 7168 # chunk 1024 # transferred 2048
lgw_spi_wb:309: BURST WRITE: to trans 6144 # chunk 1024 # transferred 3072
lgw_spi_wb:309: BURST WRITE: to trans 5120 # chunk 1024 # transferred 4096
lgw_spi_wb:309: BURST WRITE: to trans 4096 # chunk 1024 # transferred 5120
lgw_spi_wb:309: BURST WRITE: to trans 3072 # chunk 1024 # transferred 6144
lgw_spi_wb:309: BURST WRITE: to trans 2048 # chunk 1024 # transferred 7168
lgw_spi_wb:309: BURST WRITE: to trans 1024 # chunk 1024 # transferred 8192
Note: SPI burst write success
Note: SPI read success
lgw_spi_rb:371: BURST READ: to trans 8192 # chunk 1024 # transferred 1024
lgw_spi_rb:371: BURST READ: to trans 7168 # chunk 1024 # transferred 2048
lgw_spi_rb:371: BURST READ: to trans 6144 # chunk 1024 # transferred 3072
lgw_spi_rb:371: BURST READ: to trans 5120 # chunk 1024 # transferred 4096
lgw_spi_rb:371: BURST READ: to trans 4096 # chunk 1024 # transferred 5120
lgw_spi_rb:371: BURST READ: to trans 3072 # chunk 1024 # transferred 6144
lgw_spi_rb:371: BURST READ: to trans 2048 # chunk 1024 # transferred 7168
lgw_spi_rb:371: BURST READ: to trans 1024 # chunk 1024 # transferred 8192
Note: SPI burst read success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI write success
Note: SPI write success
Note: SPI read success
Note: SPI write success
Note: SPI read success
Note: SPI write success
lgw_start:845: Note: calibration started (time: 2300 ms)
Note: SPI read success
Note: SPI write success
Note: SPI read success
lgw_start:863: ERROR: CALIBRATION FAILURE (STATUS = 127)
2020-05-06 01:44:28.243 [SYS:VERB] ./deps/lgw/platform-rpi/reset_lgw.sh start 1: Forked, waiting...
2020-05-06 01:44:28.882 [SYS:INFO] Process ./deps/lgw/platform-rpi/reset_lgw.sh start 1 (pid=6782) completed
2020-05-06 01:44:28.900 [RAL:INFO] Lora gateway library version: Version: 5.0.1;
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 rxrfchain 0: enable=1 freq=904300000 rssi_offset=-166.000000 type=2 tx_enable=1 tx_notch_freq=0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 rxrfchain 1: enable=1 freq=905300000 rssi_offset=-166.000000 type=2 tx_enable=1 tx_notch_freq=0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  0: enable=1 rf_chain=0 freq=-400000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  1: enable=1 rf_chain=0 freq=-200000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  2: enable=1 rf_chain=0 freq=0 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  3: enable=1 rf_chain=0 freq=200000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  4: enable=1 rf_chain=0 freq=400000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  5: enable=1 rf_chain=1 freq=-400000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  6: enable=1 rf_chain=1 freq=-200000 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  7: enable=1 rf_chain=1 freq=0 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  8: enable=1 rf_chain=0 freq=300000 bandwidth=1 datarate=4 sync_word=0/0
2020-05-06 01:44:28.900 [RAL:VERB] SX1301 ifchain  9: enable=0 rf_chain=0 freq=0 bandwidth=0 datarate=0 sync_word=0/0
2020-05-06 01:44:28.901 [RAL:VERB] SX1301 LBT not enabled
2020-05-06 01:44:28.901 [RAL:INFO] Station device: /dev/spidev1.0 (PPS capture disabled)
2020-05-06 01:44:31.795 [RAL:ERRO] lgw_start failed: /dev/spidev1.0
2020-05-06 01:44:31.795 [any:ERRO] Closing connection to muxs - error in s2e_onMsg
2020-05-06 01:44:31.806 [TCE:VERB] Connection to MUXS closed in state -1
2020-05-06 01:44:31.806 [TCE:INFO] INFOS reconnect backoff 10s (retry 1)
Note: SPI write success
Note: SPI port closed

Any ideas?

dolfandringa commented 4 years ago

Could the patch that you apply fort platform-linux and platform-rpi be causing the calibration error? I am unclear what the patches do. They seem to be identical for linux and rpi.

dolfandringa commented 4 years ago

Any ideas?

beitler commented 4 years ago

In the log above you already identified an important low level symptom of your issue:

lgw_start:863: ERROR: CALIBRATION FAILURE (STATUS = 127)

To find the root cause, you should use the low level testing tools that come with the HAL library. Here is how you could do that:

A) Test loragw v5.0.1 with LBS patch

  1. Go into deps/lgw/platform-rpi/libloragw
  2. Type make (assuming you are on the target platform and the toolchain is installed)
  3. Now, you should have a set of test executables in that directory (test_loragw_{cal,gps,hal,reg,spi})
  4. Execute the tests (specifically the test_loragw_cal which tests the calibration). Given your above error log, we should expect the test_loragw_cal to fail.

B) Test loragw v5.0.1 original without LBS patch

  1. Inside the same directory type make clean and git checkout -- (this removes the build artefacts and reverts the code changes of the LBS patch).
  2. Type make to build the new test_loragw_* binaries.
  3. Execute test_loragw_cal again to perform the calibration test. If the test fails, the hardware is not compatible with the original loragw HAL v5.0.1 (reach out to the gateway manufacturer for help). If it succeeds the LBS patch is causing an incompatibility with your hardware.
dolfandringa commented 4 years ago

I ran the tests, with a small twist: RAKK Wireless also provides a libloragw with their packet forwarder, which also has the same tests, so I ran them there as well.

TLDR; there is no difference with or without any of the patches, or between the RAKK provided libloragw or the one basicstation provides. As long as I first reset the concentrator with ./reset_lgw.sh start 1 before the tests. There are register mismatches though with the test_loragw_reg test, but again, it doesn't matter whether I use the RAK supplied version or the vanilla libloragw or the patched version. And the RAK2245 version does work with their packet forwarder/their libloragw.

Unfortunately RAKK wireless doesn't seem willing/able to answer any questions (https://github.com/RAKWireless/rak_common_for_gateway/issues/17).

So does the register test and calibration test output point towards the issue? I have a hard time understanding what the output is saying.

I ran all the tests with sudo LORAGW_SPI=/dev/spidev1.0 ./libloragw/test_loragw_cal -a 902.7 -b 905.0 -r 1257 -t 917.0 while of course subsituting _cal for _reg for instance

RAKK supplied libloragw

test_loragw_reg

Beginning of test for loragw_reg.c
Start of register verification
.
.
.
###MISMATCH### reg number 4 read: 101 (65) default: 0 (0)
.
.
.
###MISMATCH### reg number 8 read: 127 (7f) default: 0 (0)
.
###MISMATCH### reg number 10 read: 138 (8a) default: 0 (0)
.
.
.
###MISMATCH### reg number 285 read: 218 (da) default: 0 (0)
###MISMATCH### reg number 286 read: 101 (65) default: 0 (0)
.
.
.
###MISMATCH### reg number 298 read: 7 (7) default: 0 (0)
.
.
.

End of register verification
IMPLICIT_PAYLOAD_LENGHT = 197 (should be 197)
FRAME_SYNCH_PEAK2_POS = 11 (should be 11)
PREAMBLE_SYMB1_NB = 49253 (should be 49253)
ADJUST_MODEM_START_OFFSET_SF12_RDX4 = 3173 (should be 3173)
IF_FREQ_1 = -1947 (should be -1947)
End of test for loragw_reg.c

(left out the MATCH'es for brevity)

test_loragw_cal

Library version information: Version: 5.0.1;
Radio type: 2
Radio A frequency: 902.700000 MHz
Radio B frequency: 905.000000 MHz
Number of calibration iterations: 5
Calibration command: brd: 0, chip: 1257, dac: 3

Rx A IQ mismatch: Amp:   6 Phi:  15 Rej: 52 dB Status: 143 | Debug: Rej: 48 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   3 Phi:  16 Rej: 55 dB Status: 143 | Debug: Rej: 47 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   5 Phi:  13 Rej: 53 dB Status: 143 | Debug: Rej: 47 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   3 Phi:  16 Rej: 56 dB Status: 143 | Debug: Rej: 67 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   3 Phi:  15 Rej: 56 dB Status: 143 | Debug: Rej: 49 dB Lna: 1 BB: 15 Dec:  7

WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:   5 Phi:   3 Rej: 39 dB Status: 135 | Debug: Rej: 33 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -5 Phi:   4 Rej: 39 dB Status: 135 | Debug: Rej: 31 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -3 Phi:   5 Rej: 39 dB Status: 135 | Debug: Rej: 34 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -3 Phi:  11 Rej: 41 dB Status: 135 | Debug: Rej: 35 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:   7 Phi:   5 Rej: 37 dB Status: 135 | Debug: Rej: 36 dB Lna: 1 BB: 15 Dec:  7

Tx A calibration bypassed

Tx B calibration bypassed

Rx A IQ mismatch calibration statistics on   5 iterations (min, max):
Amp:   3   6 Phi:  13  16 Rej: 52 56 dB (capt.: 47 67 dB)

Rx B IQ mismatch calibration statistics on   5 iterations (min, max):
Amp:  -5   7 Phi:   3  11 Rej: 37 41 dB (capt.: 31 36 dB)

End of radio calibration test

Basicstation supplied libloragw, with LBS patch

test_loragw_reg identical

test_loragw_cal

lgw_board_setconf:427: Note: board configuration; lorawan_public:1, clksrc:1
lgw_rxrf_setconf:488: Note: rf_chain 0 configuration; en:1 freq:902700000 rssi_offset:0.000000 radio_type:2 tx_enable:0 tx_notch_freq:0
lgw_rxrf_setconf:488: Note: rf_chain 1 configuration; en:1 freq:905000000 rssi_offset:0.000000 radio_type:2 tx_enable:0 tx_notch_freq:0
Library version information: Version: 5.0.1;
Radio type: 2
Radio A frequency: 902.700000 MHz
Radio B frequency: 905.000000 MHz
Number of calibration iterations: 5
Calibration command: brd: 0, chip: 1257, dac: 3

Rx A IQ mismatch: Amp:   3 Phi:  14 Rej: 54 dB Status: 143 | Debug: Rej: 55 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   3 Phi:  14 Rej: 56 dB Status: 143 | Debug: Rej: 65 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   2 Phi:  15 Rej: 55 dB Status: 143 | Debug: Rej: 47 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   4 Phi:  15 Rej: 58 dB Status: 143 | Debug: Rej: 52 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   4 Phi:  16 Rej: 55 dB Status: 143 | Debug: Rej: 49 dB Lna: 1 BB: 15 Dec:  7

WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:   6 Phi:   8 Rej: 42 dB Status: 135 | Debug: Rej: 33 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:   7 Phi:   7 Rej: 35 dB Status: 135 | Debug: Rej: 38 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:   4 Phi:   5 Rej: 38 dB Status: 135 | Debug: Rej: 35 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -1 Phi:  -7 Rej: 35 dB Status: 135 | Debug: Rej: 38 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -2 Phi:   2 Rej: 39 dB Status: 135 | Debug: Rej: 35 dB Lna: 1 BB: 15 Dec:  7

Tx A calibration bypassed

Tx B calibration bypassed

Rx A IQ mismatch calibration statistics on   5 iterations (min, max):
Amp:   2   4 Phi:  14  16 Rej: 54 58 dB (capt.: 47 65 dB)

Rx B IQ mismatch calibration statistics on   5 iterations (min, max):
Amp:  -2   7 Phi:  -7   8 Rej: 35 42 dB (capt.: 33 38 dB)

End of radio calibration test

Basicstation supplied libloragw, without LBS patch

Do need to manually change loragw_spi_native.c to change SPI_DEV_PATH to /dev/spidev1.0 and SPI_SPEED to 2000000, as stated before. test_loragw_reg identical

test_loragw_cal

Library version information: Version: 5.0.1;
Radio type: 2
Radio A frequency: 902.700000 MHz
Radio B frequency: 905.000000 MHz
Number of calibration iterations: 5
Calibration command: brd: 0, chip: 1257, dac: 3

Rx A IQ mismatch: Amp:   3 Phi:  14 Rej: 56 dB Status: 143 | Debug: Rej: 58 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   4 Phi:  14 Rej: 55 dB Status: 143 | Debug: Rej: 56 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   2 Phi:  15 Rej: 55 dB Status: 143 | Debug: Rej: 51 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   3 Phi:  17 Rej: 54 dB Status: 143 | Debug: Rej: 47 dB Lna: 1 BB: 15 Dec:  7
Rx A IQ mismatch: Amp:   4 Phi:  15 Rej: 60 dB Status: 143 | Debug: Rej: 49 dB Lna: 1 BB: 15 Dec:  7

WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:   7 Phi:   6 Rej: 38 dB Status: 135 | Debug: Rej: 49 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -5 Phi:  11 Rej: 39 dB Status: 135 | Debug: Rej: 34 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -2 Phi:   2 Rej: 39 dB Status: 135 | Debug: Rej: 31 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -3 Phi:   3 Rej: 39 dB Status: 135 | Debug: Rej: 36 dB Lna: 1 BB: 15 Dec:  7
WARNING: problem in calibration of radio B for image rejection
Rx B IQ mismatch: Amp:  -4 Phi:   5 Rej: 41 dB Status: 135 | Debug: Rej: 34 dB Lna: 1 BB: 15 Dec:  7

Tx A calibration bypassed

Tx B calibration bypassed

Rx A IQ mismatch calibration statistics on   5 iterations (min, max):
Amp:   2   4 Phi:  14  17 Rej: 54 60 dB (capt.: 47 58 dB)

Rx B IQ mismatch calibration statistics on   5 iterations (min, max):
Amp:  -5   7 Phi:   2  11 Rej: 38 41 dB (capt.: 31 49 dB)

End of radio calibration test
beitler commented 4 years ago

You mention that you need to run the reset_lgw.sh script prior to each test, for it to be able to complete successfully. I pointed out in a comment earlier that you could (and should) let station call this script before it tries to startup the radio. This ensures that the radio is in a clean state before the startup is done. Since the reset logic is highly platform-specific, this cannot be done by station but must be supplied in a dedicated script. Please add the following field into your station.conf inside the station_conf object:

   "reset_lgw.sh": "/path/to/reset_lgw.sh",

Adjust the path and make sure the script is executable (cmod +x). Read more about this feature in the docu: https://doc.sm.tc/station/conf.html#radio-configuration

You further mention that you need to change SPI_SPEED to 2000000 in loragw_spi_native.c for the test to pass. Do you do the same change when you build the station executable?

dolfandringa commented 4 years ago

Yes I added the reset script to the station.conf already before. And I also changed the SPI_SPEED before (I already mentioned it in earlier posts). Is there any output in the calibration an reg tests above that makes you understand why calibration fails? I can't really understand if the tests failed or succeeded. It does say WARNING: problem in calibration of radio B for image rejection for instance. So did it fail or pass?

dolfandringa commented 4 years ago

In my ticket over at https://github.com/RAKWireless/rak_common_for_gateway/issues/17 tony noticed I had TX enabled on both radios, which it shouldn't be.... :) Whoopsy. My bad. When changing tx_enable from true to false on radio_1, the calibration error disappears. Now I still have an error that the connection from basicstation to the chirpstack-gateway-bridge gets closed and basicstation closes. But at least it is a big step further. I will open a separate ticket for that if needed.

So for now, I needed to change a few things to get the rak2245 working with basicstation. I'll document them here, but I'd be happy to contribute a patch for it needed. What kind of patch would it need to be? A rak2245 variant for the rpi and linux platforms? How would that work?

This is to give the reset script enough time to complete:

diff --git a/src/s2conf.h b/src/s2conf.h
index e4c1300..ceed3a8 100644
--- a/src/s2conf.h
+++ b/src/s2conf.h
@@ -41,7 +41,7 @@
 #define DFLT_MAX_WSSDATA               2048
 #define DFLT_TC_RECV_BUFSZ        (40*1024)
 #define DFLT_TC_SEND_BUFSZ        (80*1024)
-#define DFLT_RADIO_INIT_WAIT    "\"200ms\""
+#define DFLT_RADIO_INIT_WAIT    "\"700ms\""
 #define DFLT_MAX_TXUNITS                  4
 #define DFLT_MAX_TXJOBS                 128
 #define DFLT_MAX_RXJOBS                  64

And I modified the patch file to also change the SPI speed from 8MHz to 2MHz:

diff --git a/deps/lgw/v5.0.1-rpi.patch b/deps/lgw/v5.0.1-rpi.patch
index 8a2281b..738fc56 100644
--- a/deps/lgw/v5.0.1-rpi.patch
+++ b/deps/lgw/v5.0.1-rpi.patch
@@ -125,8 +125,9 @@ index c01ed1c..0e2b64c 100644
 @@ -54,7 +54,7 @@ Maintainer: Sylvain Miermont
  #define READ_ACCESS     0x00
  #define WRITE_ACCESS    0x80
- #define SPI_SPEED       8000000
+-#define SPI_SPEED       8000000
 -#define SPI_DEV_PATH    "/dev/spidev0.0"
++#define SPI_SPEED       2000000
 +#define SPI_DEV_PATH    (getenv("LORAGW_SPI")==NULL ? "/dev/spidev0.0" : getenv("LORAGW_SPI"))
  //#define SPI_DEV_PATH    "/dev/spidev32766.0"

And then I am using this as my station.conf:

{
        "station_conf": {
                "routerid": "routerid.txt",
                "log_level": "VERBOSE",
                "log_size": 10e6,
                "log_rotate": 3,
                "reset_lgw.sh": "./deps/lgw/platform-rpi/reset_lgw.sh start 1",
                "device": "/dev/spidev1.0"
        },
        "SX1301_conf": {
                "lorawan_public": true,
                "clksrc": 1,
                "device": "/dev/spidev1.0",
                "radio_0": {
                        "type": "SX1257",
                        "rssi_offset": -166.0,
                        "tx_enable": true,
                        "antenna_gain": 0
                },
                "radio_1": {
                        "type": "SX1257",
                        "rssi_offset": -166.0,
                        "tx_enable": false,
                        "antenna_gain": 0
                }
        }
}

The number 1 in the reset script is the GPIO pin number for the RESET pin of the RAK2245. It is the pin number I am using on the OrangePi zero. For a raspberry pi it is GPIO7. Look up the pin names/numbers for your board and the RAK2245 pinout (google).