Skip to content
This repository has been archived by the owner on Aug 13, 2021. It is now read-only.

OTAA - waiting repeats.... v2 ttn and v3 both see the activation. #6

Open
Dukat-Gul opened this issue Mar 28, 2021 · 6 comments
Open

Comments

@Dukat-Gul
Copy link

Dukat-Gul commented Mar 28, 2021

console_OTAA_attempt_metadata
Hi All.
I have tried to get this working on my Raspberry Pi2 (with Dragino Lora/GPS_HAT v1.4)
https://wiki.dragino.com/index.php?title=Lora/GPS_HAT

After adjusting for Subband 2 within AU915 (which TTN uses). I run the test.py code and all I see is the Waiting repeat.

pi@raspberrypi2:~/dragino $ ./test.py Mode <- SLEEP Mode <- FSK_STDBY Mode <- SLEEP Mode <- FSK_STDBY Mode <- SLEEP 2021-03-28 16:07:16,977 - Dragino - 58 - DEBUG - Nonce = [240, 225] 2021-03-28 16:07:16,986 - DraginoConfig - 303 - INFO - Using OTAA mode 2021-03-28 16:07:16,987 - DraginoConfig - 416 - DEBUG - Converted 8/8 items 2021-03-28 16:07:16,988 - DraginoConfig - 416 - DEBUG - Converted 8/8 items 2021-03-28 16:07:16,990 - DraginoConfig - 416 - DEBUG - Converted 16/16 items 2021-03-28 16:07:16,991 - DraginoConfig - 313 - WARNING - Unable to read session details 2021-03-28 16:07:16,992 - DraginoConfig - 325 - DEBUG - GPS Baud Rate: 9600 2021-03-28 16:07:16,994 - DraginoConfig - 326 - DEBUG - GPS Serial Port: /dev/serial0 2021-03-28 16:07:16,995 - DraginoConfig - 327 - DEBUG - GPS Serial Timeout: 1 2021-03-28 16:07:16,997 - DraginoConfig - 328 - DEBUG - GPS Wait Period: 10 2021-03-28 16:07:16,998 - DraginoConfig - 329 - DEBUG - Spreading factor: 7 2021-03-28 16:07:16,999 - DraginoConfig - 330 - DEBUG - Max Power: 0F 2021-03-28 16:07:17,000 - DraginoConfig - 331 - DEBUG - Output Power: 0E 2021-03-28 16:07:17,001 - DraginoConfig - 332 - DEBUG - Sync Word: 34 2021-03-28 16:07:17,002 - DraginoConfig - 333 - DEBUG - RX CRC: True 2021-03-28 16:07:17,003 - DraginoConfig - 334 - DEBUG - Frame Count Filename: .lora_fcount 2021-03-28 16:07:17,004 - DraginoConfig - 335 - DEBUG - Auth mode: OTAA 2021-03-28 16:07:17,006 - DraginoConfig - 349 - DEBUG - Device EUI: 00 60 59 E0 EF F9 49 A3 2021-03-28 16:07:17,008 - DraginoConfig - 352 - DEBUG - App EUI: 70 B3 D5 7E D0 03 FE 74 2021-03-28 16:07:17,009 - DraginoConfig - 355 - DEBUG - App Key: 0A 50 50 01 40 07 06 00 E3 0D E0 F2 09 D0 4D 04 2021-03-28 16:07:17,016 - DraginoConfig - 365 - DEBUG - Joined False 2021-03-28 16:07:17,018 - Dragino - 171 - DEBUG - Performing OTAA Join 2021-03-28 16:07:17,019 - Dragino - 175 - INFO - App key = [10, 80, 80, 1, 64, 7, 6, 0, 227, 13, 224, 242, 9, 208, 77, 4] 2021-03-28 16:07:17,020 - Dragino - 176 - INFO - App eui = [112, 179, 213, 126, 208, 3, 254, 116] 2021-03-28 16:07:17,021 - Dragino - 177 - INFO - Dev eui = [0, 96, 89, 224, 239, 249, 73, 163] 2021-03-28 16:07:17,023 - Dragino - 102 - INFO - Frequency = 916.8 Mode <- STDBY Mode <- TX Waiting 2021-03-28 16:07:17,092 - Dragino - 148 - DEBUG - TX Complete Mode <- STDBY Mode <- RXCONT Waiting Waiting Waiting Waiting Waiting Waiting
Similar reported issue - jeroennijhof#5

When I have looked at the console of the v2 TTN - I see that the activation request was seen.

{ "time": "2021-03-28T07:57:37.449676372Z", "frequency": 917.2, "modulation": "LORA", "data_rate": "SF7BW125", "coding_rate": "4/5", "gateways": [ { "gtw_id": "eui-00800000a0003e55", "timestamp": 3476306715, "time": "2021-03-28T07:57:37.39437Z", "channel": 2, "rssi": -110, "snr": -3.5 }, { "gtw_id": "eui-60c5a8fffe76f86a", "timestamp": 1912733067, "time": "2021-03-28T07:57:37.394368Z", "channel": 2, "rssi": -120, "snr": -7.3 } ] }

For fun I also added to the v3 and the following was a little more detailed, but still im at a loss as to the problem..

`Last seen7 minutes ago
arrow_upwardn/a
arrow_downwardn/a
Created 7 minutes ago

16:07:17
Drop join-request
MIC mismatch
v3_OTAA_attempt_metadata

16:07:17
Join-request to cluster-local Join Server failed
MIC mismatch

16:07:17
Send join-request to cluster-local Join Server
JoinEUI
70B3D57ED003FE74
DevEUI
006059E0EFF949A3
Selected MAC version
1.0.2

16:07:17
Receive join-request
JoinEUI
70B3D57ED003FE74
DevEUI
006059E0EFF949A3
Bandwidth
125000
SNR
-6.2
RSSI
-110
Raw payload
0074FE03D07ED5B370A349F9EFE0596000F0EDE55EB292
Event details
Close event info
Eve`
v2_OTAA_attempt_metadata

@BNNorman
Copy link

I use the code, from 9 months ago, on a project and it worked fine in the UK (815Mhz).

The MIC Mismatch you get from using V3 suggests to me that V3, somehow, calculates the MIC differently so you should stick with V2 for now. Look at dragino\LoraWAN\JoinAcceptPayload.py and JoinRequestPayload.py - you will find an example of the compute_mic() method.

However, 'waiting' forever suggests the join-accept response has been missed or not sent. What does your logfile have in it? If you look in dragino.py there's an on_rx_done() method on line 118 which logs the message "Received message". If the message is a JOIN_ACCEPT it logs 'Join resp' to the log file then validates the MIC etc. This should give you some idea what is/isn't happening.

@pjb304
Copy link

pjb304 commented Mar 29, 2021

I'm afraid I'm not sure what's going on here - I suspect there's something else that needs changing to adapt it to the different region. As it works fine on both v2 & v3 in the Uk

@Dukat-Gul
Copy link
Author

Thanks @pjb304 & @BNNorman .
Not sure how to further turn on logging - have experimented with editing dragino.py and adjusting the

D = Dragino("dragino.ini", logging_level=logging.INFO)

changing it to DEBUG - but nothing of note was showing on stdout or elsewhere.

Also tried -
DEFAULT_LOG_LEVEL = logging.DEBUG

Anyhow - I made a small change in the v3 console and updated my settings to be 1.0.1 Lorawan and I got a few extra steps, no sign of the MIC errors now.
v3_OTAA_slightprogress_metadata_rx-freq_9233

I have a feeling the issue is that I am not receiving anything. When I tweaked the dragino/FrequncyPlan.py to align to the AU915 (subband 2) frequencies for TTN in Australia, I didnt see any place to adjust the down (RX) frequencies.

As you can see from this - https://github.com/Fluent-networks/floranet/blob/f025825fa234194646d9831bd52fa3a3a55c0666/floranet/lora/bands.py

AU915 TX freq are 200khz stepped - Channel 8 (916.8) through Ch15 (917.5) plus a 500khz Ch65 (917.5) but unlike the EU868 the downlink (RX) frequencies are (also for US915) not the same as the uplink (TX).
They are 8 channels numbered 0 to 7 utilizing 500 kHz BW starting at 923.3 MHz and incrementing by 600 kHz to 927.5 MHz.

OTAA_AU915_tx_rx-freq

I have tried a few quick and dirty edits but all without any progress.
For example I edited a few places where I saw 868

dragino/SX127x/LoRa.py: def init(self, verbose=True, do_calibration=True, calibration_freq=923):
dragino/SX127x/LoRa.py: :param calibration_freq: call rx_chain_calibration with this parameter. Default is 923
dragino/SX127x/LoRa.py: def rx_chain_calibration(self, freq=923.3):

Any suggestions as to next (easy) steps I can try? Or will it require a significant code edit to have a TX and RX frequency alignment for this region?

@pjb304
Copy link

pjb304 commented Mar 29, 2021

Yes, the code does currently have the assumption that uplink and downlink happen on the same frequency.

I think the way to change that would be to use similar calls to those in _choose_freq in the on_tx_done to change onto the correct frequency before entering RX mode.

As for the calibration I'm afraid I'm not sure how best to change that to 923MHz.

@Dukat-Gul
Copy link
Author

Dukat-Gul commented Mar 29, 2021

Yeah.... cool Thanks.

I tried (i think) something along the lines of your suggestion prior to you suggesting it. As I looked at some of the other other forks - specifically the https://github.com/ryanzav/LoRaWAN/blob/master/otaa_helium.py
and he did it for the US downlink (which is the same as mine in AU).
I put into FrequncyPlan CH0 as the 923.3
then edited dragino.py:

def on_tx_done(self):
    """
        Callback on TX complete is signaled using I/O
    """
    self.clear_irq_flags(TxDone=1)
    self.set_mode(MODE.STDBY)
    self.set_dio_mapping([0, 0, 0, 0, 0, 0])
    self.set_invert_iq(1)
    self.reset_ptr_rx()
    self.set_freq(LORA_FREQS.CH0)
    self.set_spreading_factor(7)
    self.set_bw(9)
    self.set_rx_crc(False)
    self.set_mode(MODE.RXCONT)

didnt seem to hit the mark, or make any real difference. but its late here.... time to goto bed and perhaps tomorrow have another look

@justin-cotarla
Copy link

According to the specs, in the US902-928 channels:

RX1 Channel Number = Transmit Channel Number modulo 8

In other words, there are two sets of frequencies in the US frequency plan, one for uplink and one for downlink. If you use the first uplink channel, you will get a response on the first downlink channel.

I modified the code slightly to this effect:

FrequencyPlan.py

UPLINK_FREQS = (903.9, 904.1, 904.3, 904.5, 904.7, 904.9, 905.1, 905.3)
DOWNLINK_FREQS = (923.3, 923.9, 924.5, 925.1, 925.7, 926.3, 926.9, 927.5)

Dragino.py

def _choose_freq(self, uplink=False):
    if self.freq_index is None:
        self.freq_index = randrange(len(UPLINK_FREQS)) #Pick a random frequency

    if uplink:
        available = UPLINK_FREQS
    else:
        available = DOWNLINK_FREQS

    freq = available[self.freq_index]
    self.set_mode(MODE.SLEEP)
    self.set_freq(freq)
    self.logger.info("Frequency = %s", freq)

Then, every time there would be an uplink (such as when registering), I call self._choose_freq(uplink=True), and whenever I need to listen to a response, such as on_tx_done, I call self._choose_freq(uplink=False).

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants