search

forrestfiller / -arduino-feather-32u4-lora

A quick test of MCCIs Arduino-LMIC fork using Adafruit's Feather 32u4 Lora board (ATmega32u4) in lieu of the larger (256k) Feather M0.
9 stars 0 forks source link

Device not joining network #2

Open fiveohhh opened 6 years ago

fiveohhh commented 6 years ago

I have a multitech conduit setup and running the Lora pkt fwd app. I also have an adafruit 32u4 feather running this application. I can see my device sending an activation packet, but it never seems to get the response even though the gateway appears to be sending it. Any thoughts on where to start looking?

Gateway logs:

##### 2017-11-25 16:28:31 GMT #####
### [UPSTREAM] ###
# RF packets received by concentrator: 1
# CRC_OK: 100.00%, CRC_FAIL: 0.00%, NO_CRC: 0.00%
# RF packets forwarded: 1 (23 bytes)
# PUSH_DATA datagrams sent: 0 (0 bytes)
# PUSH_DATA acknowledged: 0.00%
### [DOWNSTREAM] ###
# PULL_DATA sent: 0 (0.00% acknowledged)
# PULL_RESP(onse) datagrams received: 0 (0 bytes)
# RF packets sent to concentrator: 0 (0 bytes)
# TX errors: 0
### BEACON IS DISABLED!
### [JIT] ###
# INFO: JIT queue contains 0 packets.
# INFO: JIT queue contains 0 beacons.
### GPS IS DISABLED!
### [PERFORMANCE] ###
# Upstream radio packet quality: 100.00%.
# Semtech status report send.
##### END #####
10:28:31  INFO: [TTN] bridge.us-west.thethings.network RTT 69
10:28:31  INFO: [TTN] send status success for bridge.us-west.thethings.network
lgw_receive:1165: FIFO content: 1 44 3 7 c1
lgw_receive:1184: [7 17]
Note: LoRa packet
10:28:52  INFO: Disabling GPS mode for concentrator's counter...
10:28:52  INFO: host/sx1301 time offset=(1511626213s:194685µs) - drift=-393µs
10:28:52  INFO: Enabling GPS mode for concentrator's counter.

Device output:

Starting
RXMODE_RSSI
963588: engineUpdate, opmode=0x808
Packet queued
963724: EV_JOINING
963780: engineUpdate, opmode=0xc
964343: Unknown event
964417: engineUpdate, opmode=0x88c
964613: TXMODE, freq=903900000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 6
1300343: RXMODE_SINGLE, freq=923300000, SF=10, BW=500, CR=4/5, IH=0

I also see an activation packet come into the ttn logs with the following meta:

{
  "time": "2017-11-25T16:35:07.749987353Z",
  "frequency": 904.6,
  "modulation": "LORA",
  "data_rate": "SF8BW500",
  "coding_rate": "4/5",
  "gateways": [
    {
      "gtw_id": "xxxx",
      "timestamp": 1492334560,
      "time": "2017-11-25T16:35:05Z",
      "channel": 8,
      "rssi": -104,
      "snr": 9.25
    }
  ]
}
fiveohhh commented 6 years ago

I just realized I don't have dio[1] set. I set that and it seems to do more, but still fails The debug output looks like this:

Starting
RXMODE_RSSI
584131: engineUpdate, opmode=0x808
Packet queued
584271: EV_JOINING
584327: engineUpdate, opmode=0xc
584890: Unknown event
17
584965: engineUpdate, opmode=0x88c
585158: TXMODE, freq=904700000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
920762: RXMODE_SINGLE, freq=925700000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 921078 rxtime: 920806 entry-rxtime: 272 now-entry: 7 rxtime-txend: 312692
start single rx: now-rxtime: 7
983838: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 986077 rxtime: 983882 entry-rxtime: 2195 now-entry: 6 rxtime-txend: 375768
986371: engineUpdate, opmode=0xc
1015406: engineUpdate, opmode=0xc
1015973: Unknown event
17
1016052: engineUpdate, opmode=0x88c
1016250: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
1330383: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 1330385 rxtime: 1330299 entry-rxtime: 86 now-entry: 7 rxtime-txend: 312524
start single rx: now-rxtime: 6
1393626: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 1395866 rxtime: 1393543 entry-rxtime: 2323 now-entry: 6 rxtime-txend: 375768
1396176: engineUpdate, opmode=0xc
1865792: engineUpdate, opmode=0xc
1866358: Unknown event
17
1866438: engineUpdate, opmode=0x88c
1866636: TXMODE, freq=904900000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
2202494: RXMODE_SINGLE, freq=926300000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 2202811 rxtime: 2202410 entry-rxtime: 401 now-entry: 7 rxtime-txend: 312692
start single rx: now-rxtime: 7
2265570: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 2267808 rxtime: 2265486 entry-rxtime: 2322 now-entry: 6 rxtime-txend: 375768
2268108: engineUpdate, opmode=0xc
2276971: engineUpdate, opmode=0xc
2277539: Unknown event
17
2277618: engineUpdate, opmode=0x88c
2277816: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
2591948: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 2591951 rxtime: 2591864 entry-rxtime: 87 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 6
2655191: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 2657430 rxtime: 2655108 entry-rxtime: 2322 now-entry: 6 rxtime-txend: 375768
2657741: engineUpdate, opmode=0xc
3602437: engineUpdate, opmode=0xc
3603002: Unknown event
17
3603082: engineUpdate, opmode=0x88c
3603280: TXMODE, freq=905300000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
3938884: RXMODE_SINGLE, freq=927500000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 3939201 rxtime: 3938928 entry-rxtime: 273 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 7
4001960: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 4004198 rxtime: 4002004 entry-rxtime: 2194 now-entry: 7 rxtime-txend: 375768
4004498: engineUpdate, opmode=0xc
4012080: engineUpdate, opmode=0xc
4012646: Unknown event
17
4012727: engineUpdate, opmode=0x88c
4012925: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
4327057: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 4327133 rxtime: 4327101 entry-rxtime: 32 now-entry: 7 rxtime-txend: 312524
start single rx: now-rxtime: 6
4390300: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 4392541 rxtime: 4390345 entry-rxtime: 2196 now-entry: 6 rxtime-txend: 375768
4393006: engineUpdate, opmode=0xc
4402481: engineUpdate, opmode=0xc
4403047: Unknown event
17
4403128: engineUpdate, opmode=0x88c
4403325: TXMODE, freq=905100000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 6
4739054: RXMODE_SINGLE, freq=926900000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 4739371 rxtime: 4738971 entry-rxtime: 400 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 6
4802130: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 4804370 rxtime: 4802047 entry-rxtime: 2323 now-entry: 6 rxtime-txend: 375768
4804669: engineUpdate, opmode=0xc
4861860: engineUpdate, opmode=0xc
4862426: Unknown event
17
4862506: engineUpdate, opmode=0x88c
4862705: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
5176837: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 5176925 rxtime: 5176881 entry-rxtime: 44 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 6
5240081: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 5242448 rxtime: 5240125 entry-rxtime: 2323 now-entry: 6 rxtime-txend: 375768
5242756: engineUpdate, opmode=0xc
5817132: engineUpdate, opmode=0xc
5817698: Unknown event
17
5817778: engineUpdate, opmode=0x88c
5817976: TXMODE, freq=904100000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
6153705: RXMODE_SINGLE, freq=923900000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 6154022 rxtime: 6153621 entry-rxtime: 401 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 7
6216781: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 6219019 rxtime: 6216697 entry-rxtime: 2322 now-entry: 6 rxtime-txend: 375768
6219319: engineUpdate, opmode=0xc
6267591: engineUpdate, opmode=0xc
6268157: Unknown event
17
6268238: engineUpdate, opmode=0x88c
6268436: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
6582441: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 6582444 rxtime: 6582485 entry-rxtime: 4294967255 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 7
6645685: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 6647923 rxtime: 6645729 entry-rxtime: 2194 now-entry: 6 rxtime-txend: 375768
6648232: engineUpdate, opmode=0xc
7595970: engineUpdate, opmode=0xc
7596536: Unknown event
17
7596616: engineUpdate, opmode=0x88c
7596813: TXMODE, freq=904500000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
7932542: RXMODE_SINGLE, freq=925100000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 7932859 rxtime: 7932458 entry-rxtime: 401 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 7
7995618: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 7997856 rxtime: 7995534 entry-rxtime: 2322 now-entry: 6 rxtime-txend: 375768
7998157: engineUpdate, opmode=0xc
8026083: engineUpdate, opmode=0xc
8026650: Unknown event
17
8026729: engineUpdate, opmode=0x88c
8026928: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
8340931: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 8340934 rxtime: 8340975 entry-rxtime: 4294967255 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 7
8404303: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 8406542 rxtime: 8404219 entry-rxtime: 2323 now-entry: 7 rxtime-txend: 375768
8407006: engineUpdate, opmode=0xc
9338026: engineUpdate, opmode=0xc
9338591: Unknown event
17
9338671: engineUpdate, opmode=0x88c
9338870: TXMODE, freq=905300000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
9674729: RXMODE_SINGLE, freq=927500000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 9675044 rxtime: 9674645 entry-rxtime: 399 now-entry: 8 rxtime-txend: 312692
start single rx: now-rxtime: 7
9737805: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 9740045 rxtime: 9737721 entry-rxtime: 2324 now-entry: 6 rxtime-txend: 375768
9740345: engineUpdate, opmode=0xc
9769802: engineUpdate, opmode=0xc
9770369: Unknown event
17
9770448: engineUpdate, opmode=0x88c
9770646: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
10084652: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 10084657 rxtime: 10084696 entry-rxtime: 4294967257 now-entry: 7 rxtime-txend: 312524
start single rx: now-rxtime: 6
10147895: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 10150134 rxtime: 10147940 entry-rxtime: 2194 now-entry: 6 rxtime-txend: 375768
10150449: engineUpdate, opmode=0xc
10446144: engineUpdate, opmode=0xc
10446714: Unknown event
17
10446799: engineUpdate, opmode=0x88c
10447000: TXMODE, freq=904100000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
10782602: RXMODE_SINGLE, freq=923900000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 10783047 rxtime: 10782646 entry-rxtime: 401 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 7
10845806: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 10848044 rxtime: 10845722 entry-rxtime: 2322 now-entry: 6 rxtime-txend: 375768
10848351: engineUpdate, opmode=0xc
10870189: engineUpdate, opmode=0xc
10870758: Unknown event
17
10870842: engineUpdate, opmode=0x88c
10871045: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 6
11185177: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 11185184 rxtime: 11185222 entry-rxtime: 4294967258 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 7
11248422: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 11250660 rxtime: 11248466 entry-rxtime: 2194 now-entry: 7 rxtime-txend: 375768
11250978: EV_JOIN_FAILED
11251051: engineUpdate, opmode=0xc
11412104: engineUpdate, opmode=0xc
11412673: Unknown event
17
11412759: engineUpdate, opmode=0x88c
11412959: TXMODE, freq=904900000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 6
11748688: RXMODE_SINGLE, freq=926300000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 11749003 rxtime: 11748604 entry-rxtime: 399 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 7
11811636: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 11813874 rxtime: 11811680 entry-rxtime: 2194 now-entry: 7 rxtime-txend: 375768
11814182: engineUpdate, opmode=0xc
11852874: engineUpdate, opmode=0xc
11853444: Unknown event
17
11853528: engineUpdate, opmode=0x88c
11853730: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
12167864: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 12167870 rxtime: 12167908 entry-rxtime: 4294967258 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 7
12231108: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 12233346 rxtime: 12231152 entry-rxtime: 2194 now-entry: 7 rxtime-txend: 375768
12233663: engineUpdate, opmode=0xc
12733452: engineUpdate, opmode=0xc
12734021: Unknown event
17
12734106: engineUpdate, opmode=0x88c
12734308: TXMODE, freq=904700000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
13070165: RXMODE_SINGLE, freq=925700000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 13070480 rxtime: 13070081 entry-rxtime: 399 now-entry: 6 rxtime-txend: 312692
start single rx: now-rxtime: 7
13133113: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 13135351 rxtime: 13133157 entry-rxtime: 2194 now-entry: 7 rxtime-txend: 375768
13135812: engineUpdate, opmode=0xc
13137264: engineUpdate, opmode=0xc
13137834: Unknown event
17
13137917: engineUpdate, opmode=0x88c
13138120: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
13452251: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 13452256 rxtime: 13452167 entry-rxtime: 89 now-entry: 6 rxtime-txend: 312524
start single rx: now-rxtime: 7
13515495: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 13517734 rxtime: 13515411 entry-rxtime: 2323 now-entry: 6 rxtime-txend: 375768
13518053: engineUpdate, opmode=0xc
14508940: engineUpdate, opmode=0xc
14509510: Unknown event
17
14509594: engineUpdate, opmode=0x88c
14509797: TXMODE, freq=905300000, len=23, SF=10, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 7
14845653: RXMODE_SINGLE, freq=927500000, SF=10, BW=500, CR=4/5, IH=0
rxtimeout: entry: 14845970 rxtime: 14845569 entry-rxtime: 401 now-entry: 7 rxtime-txend: 312692
start single rx: now-rxtime: 7
14908601: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 14910839 rxtime: 14908645 entry-rxtime: 2194 now-entry: 7 rxtime-txend: 375768
14911147: engineUpdate, opmode=0xc
14958034: engineUpdate, opmode=0xc
14958604: Unknown event
17
14958688: engineUpdate, opmode=0x88c
14958890: TXMODE, freq=904600000, len=23, SF=8, BW=500, CR=4/5, IH=0
start single rx: now-rxtime: 7
15273022: RXMODE_SINGLE, freq=923900000, SF=7, BW=500, CR=4/5, IH=0
rxtimeout: entry: 15273029 rxtime: 15273066 entry-rxtime: 4294967259 now-entry: 7 rxtime-txend: 312524
start single rx: now-rxtime: 6
15336265: RXMODE_SINGLE, freq=923300000, SF=12, BW=500, CR=4/5, IH=0
rxtimeout: entry: 15338505 rxtime: 15336310 entry-rxtime: 2195 now-entry: 6 rxtime-txend: 375768
15338822: engineUpdate, opmode=0xc

I keep seeing the activation requests, in the console, but the device doesn't seem to be getting the responses. I read some other peoples issues on timing so I added this line to my setup, but still doesn't help:

LMIC_setClockError(MAX_CLOCK_ERROR * 1 / 100);
terrillmoore commented 6 years ago

Adding the LMIC_setClockError() is a good thing. Try making it MAX_CLOCK_ERROR * 10 / 100 (i.e., much more.)

Also make sure that you have set subband 1 (out of 0..7).

Which packet forwarder are you using on the Conduit? We have had bad luck with everything except Kersing 2_1r5.

fiveohhh commented 6 years ago

I tried upping it to 10%, but still no dice. I'm using the sketch as is so I believe it is already set to subband 1 (https://github.com/forrestfiller/-arduino-feather-32u4-lora/blob/master/ttn-ny-otaa-feather-us915.ino#L200)

I'm not sure what pkt forwarder I'm using. I followed these instructions: https://www.thethingsnetwork.org/docs/gateways/multitech/mlinux.html

It looks like that installs kersing mp-packet-forwarder 3.0.0r14

Should I instead remove that and use the 2.1r5 poly packet forwarder?

terrillmoore commented 6 years ago

Should I instead remove that and use the 2.1r5 poly packet forwarder?

It's probably not the problem, but... worth trying anyway. I have definitely had downlink/join problems with the Conduit that were resolved by changing the packet forwarder. Exactly the same symptoms, uplink worked (as it is in your case).

The clincher would be if you had a second device and you could run the raw-feather app, to see if your devices are sending and receiving using the LMIC code. But often people don't have that, so... Your logs show that you're starting receives and then timing out; in my experience, as long as the antenna is correct and so forth, you'll see traffic if the gateway is sending it.

If you want, you can join The Things Network NYC slack, there are a number of people who can probably help. Find info via https://thethings.nyc -- you'll have to send an email to get an invitation.