Lora python assertion error

[SloMusti]

23.12.17 15:52:18 (+0100) Traceback (most recent call last):
23.12.17 15:52:18 (+0100)   File "pira/boot.py", line 194, in process
23.12.17 15:52:18 (+0100)     module.process(self.modules)
23.12.17 15:52:18 (+0100)   File "pira/modules/lora.py", line 55, in process
23.12.17 15:52:18 (+0100)     self._lora = LoRa(verbose=False)
23.12.17 15:52:18 (+0100)   File "pira/hardware/lora/SX127x/LoRa.py", line 100, in __init__
23.12.17 15:52:18 (+0100)     self.rx_chain_calibration(calibration_freq)
23.12.17 15:52:18 (+0100)   File "pira/hardware/lora/SX127x/LoRa.py", line 856, in rx_chain_calibration
23.12.17 15:52:18 (+0100)     self.set_freq(freq_bkup)
23.12.17 15:52:18 (+0100)   File "pira/hardware/lora/SX127x/LoRa.py", line 282, in set_freq
23.12.17 15:52:18 (+0100)     assert self.mode == MODE.SLEEP or self.mode == MODE.STDBY or self.mode == MODE.FSK_STDBY
23.12.17 15:52:18 (+0100) AssertionError```

[SloMusti]

These errors are generally associated with hardware connection problems, failing to communicate with the RF module. We can add a clearer error message, but first need to confirm this is an HW issue.

[SloMusti]

The following output happens if there is no module attached, so we should definitely handle this as no hardware connected, note that the state register return 0 in that case. But we are also seeing this error if the value is 6 or something else, so in that case it is not hardware disconnected.

https://github.com/IRNAS/PiRA-zero-firmware/issues
05.01.18 08:48:08 (+0100) Lora mode register value 0
05.01.18 08:48:08 (+0100) Error while running processing in module 'pira.modules.lora'.
05.01.18 08:48:08 (+0100) Traceback (most recent call last):
05.01.18 08:48:08 (+0100)   File "pira/boot.py", line 201, in process
05.01.18 08:48:08 (+0100)     module.process(self.modules)
05.01.18 08:48:08 (+0100)   File "pira/modules/lora.py", line 55, in process
05.01.18 08:48:08 (+0100)     self._lora = LoRa(verbose=False)
05.01.18 08:48:08 (+0100)   File "pira/hardware/lora/SX127x/LoRa.py", line 101, in __init__
05.01.18 08:48:08 (+0100)     self.rx_chain_calibration(calibration_freq)
05.01.18 08:48:08 (+0100)   File "pira/hardware/lora/SX127x/LoRa.py", line 857, in rx_chain_calibration
05.01.18 08:48:08 (+0100)     self.set_freq(freq_bkup)
05.01.18 08:48:08 (+0100)   File "pira/hardware/lora/SX127x/LoRa.py", line 283, in set_freq
05.01.18 08:48:08 (+0100)     assert self.mode == MODE.SLEEP or self.mode == MODE.STDBY or self.mode == MODE.FSK_STDBY
05.01.18 08:48:08 (+0100) AssertionError

[SloMusti]

The issue is unlikely hardware related, because it happens on multiple board versions, locations and on boards that previously worked well.

[SloMusti]

I have implemented a more rigorous reset method: https://github.com/IRNAS/PiRA-zero-firmware/blob/master/pira/modules/lora.py#L56

Behaviour is however not as expected, because if initialization fails, Lora should try to be re-initialized every time, but happens only after reboot, possibly an issue with this line: https://github.com/IRNAS/PiRA-zero-firmware/blob/master/pira/modules/lora.py#L68

Assertion error is now handled here, but the issue is not resolved: https://github.com/IRNAS/PiRA-zero-firmware/blob/master/pira/hardware/lora/SX127x/LoRa.py#L98

At some point I have observed the module not entering the incorrect mode, but can not replicate that again.

[SloMusti]

Possibly relevant: Lora-net/LoRaMac-node#199

[SloMusti]

Confirmed that this is a softare issue as it stopped working after commit 9c4b5bd, possibly worked also on 5596554 .

[SloMusti]

Interestingly, there is one device where this works on c7d51ba, while on some others it does not on same commit.

[SloMusti]

I found the difference: Lora works on Resin OS 2.2.0+rev1 (prod) but not on the next version Resin OS 2.7.8+rev1 (prod), confirmed on multiple devices. Now we need to figure out what breaks the lora library, SPI communication or anything along the lines.

[SloMusti]

Note he problem is present also on the latest Raspbian Lite, so it may be correlated to external libraries.

[SloMusti]

This may be relevant, some change in SPI speed sandeepmistry/node-sx127x#5 (comment)

[SloMusti]

Adding the variable RESIN_HOST_CONFIG_core_freq with value 250 a change in error has been observed, now lora enters the wrong state 0x03 while previously this was 0x06

[telphan]

The issue is independent of the rpi firmware (tested). As this issue is also present on raspbian my only guess now is for the issue to be with the kernel (or maybe the kernel configuration), so will give this theory a spin soon.

[SloMusti]

Referencing another issue: mayeranalytics/pySX127x#23 (comment)

[SloMusti]

SPI speed fixed with 1b868fe although this is more of a workaround given that we dont know what changed in RPi firmware and caused the problem and likely some other changes.

[mayeranalytics]

...this is more of a workaround...

For some reason the spidev max clock speed defaults to 12MHz now instead of 10MHz previously. (If you look at the SPI speeds that the BCM283x processors actually support, i.e. 125MHz/(2n+1) according to this here, neither of these numbers makes any sense.)
And 10MHz happens to be the max clock speed that the SX127x can support.
RPi internals are obscure (try to find the processor datasheet!), so within the given limitations this is a sensible fix.

[SloMusti]

@mayeranalytics agreed, I have tried this fix weeks ago but with 7.8 MHz speed according to: http://www.takaitra.com/posts/492 where 5MHz is not even listed, but that list is wrong it would seem.

[charlesmarseille]

I still see this issue. Is there a fix finally?