Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

EV_JOINING not success #311

Open
svelmurugan92 opened this issue May 3, 2019 · 29 comments
Open

EV_JOINING not success #311

svelmurugan92 opened this issue May 3, 2019 · 29 comments
Assignees
@svelmurugan92 @terrillmoore
Labels
question

Comments

@svelmurugan92
Copy link

With the current master changes, tried to build the example sketch in catena 4450 and catena 4612. While doing the step clear the FRAM and redo the provisioning.
Then join not happening, EV_JOINING not success.

-------------------------------------------------------------------------------
This is the catena4612_simple program V0.1.1.
Target network: The Things Network / in866
Enter 'help' for a list of commands.
(remember to select 'Line Ending: Newline' at the bottom of the monitor window.)
SYSCLK: 32 MHz
USB enabled
message cycle time 30 seconds for 10 messages
CPU Unique ID: 08-20-47-04-32-37-47-04-33-34-37-39-47-00-43-00
--------------------------------------------------------------------------------

LoRaWAN init: ?CatenaBase::GetAbpProvisioningInfo: failing
succeeded
EUI64: 00-02-cc-01-00-00-01-97
Platform Flags:  0x00007019
Operating Flags:  0x00000001
FLASH found, put power down
vBat:    2114 mV
vBus:    4259 mV
BME280:  T: 29 P: 100435 RH: 43
Si1133:  67 IR, 33 White, 0 UV
EV_JOINING
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART
EV_JOIN_TXCOMPLETE
EV_TXSTART

Tried the compliance test code in 4450. Still same problem, joining not happened.

Starting
Packet queued
313387: EV_JOINING
645082: EV_TXSTART: ch 0 rps=0x1 (SF7 BW125 CR 4/5 Crc IH=0), datarate 5, opmode 88C
953455: EV_RXSTART: freq=865.0 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 648984, delta ms 4871
1005940: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 648984, delta ms 5711
1045937: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
1293838: EV_TXSTART: ch 1 rps=0x1 (SF7 BW125 CR 4/5 Crc IH=0), datarate 5, opmode 88C
1602212: EV_RXSTART: freq=865.4 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 1297740, delta ms 4871
1654696: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 1297740, delta ms 5711
1694696: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
2311232: EV_TXSTART: ch 2 rps=0x1 (SF7 BW125 CR 4/5 Crc IH=0), datarate 5, opmode 88C
2619605: EV_RXSTART: freq=865.9 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 2315134, delta ms 4871
2672089: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 2315134, delta ms 5711
2712087: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
2925129: EV_TXSTART: ch 0 rps=0x2 (SF8 BW125 CR 4/5 Crc IH=0), datarate 4, opmode 88C
3229196: EV_RXSTART: freq=865.0 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 2932245, delta ms 4751
3289200: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 2932245, delta ms 5711
3329197: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
4436769: EV_TXSTART: ch 1 rps=0x2 (SF8 BW125 CR 4/5 Crc IH=0), datarate 4, opmode 88C
4740836: EV_RXSTART: freq=865.4 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 4443884, delta ms 4751
4800839: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 4443884, delta ms 5711
4840837: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
5202884: EV_TXSTART: ch 2 rps=0x2 (SF8 BW125 CR 4/5 Crc IH=0), datarate 4, opmode 88C
5506951: EV_RXSTART: freq=865.9 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 5209999, delta ms 4751
5566955: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 5209999, delta ms 5711
5606953: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
6501534: EV_TXSTART: ch 0 rps=0x3 (SF9 BW125 CR 4/5 Crc IH=0), datarate 3, opmode 88C
6811578: EV_RXSTART: freq=865.0 rps=0x83 (SF9 BW125 CR 4/5 NoCrc IH=0), datarate 3, opmode 88C, txend 6514435, delta ms 4754
6871390: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 3, opmode 88C, txend 6514435, delta ms 5711
6911387: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
7375946: EV_TXSTART: ch 1 rps=0x3 (SF9 BW125 CR 4/5 Crc IH=0), datarate 3, opmode 88C
7685992: EV_RXSTART: freq=865.4 rps=0x83 (SF9 BW125 CR 4/5 NoCrc IH=0), datarate 3, opmode 88C, txend 7388848, delta ms 4754
7745803: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 3, opmode 88C, txend 7388848, delta ms 5711
7785861: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
9686407: EV_TXSTART: ch 2 rps=0x3 (SF9 BW125 CR 4/5 Crc IH=0), datarate 3, opmode 88C
9996452: EV_RXSTART: freq=865.9 rps=0x83 (SF9 BW125 CR 4/5 NoCrc IH=0), datarate 3, opmode 88C, txend 9699308, delta ms 4754
10056263: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 3, opmode 88C, txend 9699308, delta ms 5711
10096258: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
10631994: EV_TXSTART: ch 0 rps=0x4 (SF10 BW125 CR 4/5 Crc IH=0), datarate 2, opmode 88C
10952719: EV_RXSTART: freq=865.0 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 2, opmode 88C, txend 10655192, delta ms 4760
11012147: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 2, opmode 88C, txend 10655192, delta ms 5711
11052141: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
15120099: EV_TXSTART: ch 1 rps=0x4 (SF10 BW125 CR 4/5 Crc IH=0), datarate 2, opmode 88C
15440825: EV_RXSTART: freq=865.4 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 2, opmode 88C, txend 15143298, delta ms 4760
15500254: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 2, opmode 88C, txend 15143298, delta ms 5711
15540251: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
15855397: EV_TXSTART: ch 2 rps=0x4 (SF10 BW125 CR 4/5 Crc IH=0), datarate 2, opmode 88C
16176123: EV_RXSTART: freq=865.9 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 2, opmode 88C, txend 15878595, delta ms 4760
16235551: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 2, opmode 88C, txend 15878595, delta ms 5711
16275612: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80

Please share your views
@terrillmoore
Copy link
Member

Vel, having been out for more than a week, I'm way behind and won't be able to look at this soon.

Can you please use the compliance app and git bisect on the LMIC, to find the change that broke this?

Thanks,
--Terry

@terrillmoore
Copy link
Member

For what it's worth, I noticed that JOIN had become more fragile and required that I widen the clock tolerances in order to make it robust. I thought it was beause of the new event reporting (particularly receive). However, I also notice that your log stops at datarate 2, can you please check that the first tx goes all the way to datarate 0 before going back to datarate 5. Also tell me what is happening at the gateway (which downlink window is being used, and what timing/channel/datarate).

@svelmurugan92
Copy link
Author

Hello Terry,

I tried the same today, Now join working. Looks like its not a lmic code problem. Maybe a network issue.
BTW, Checked the datarate, first Tx itself starting at datarate 5.
Attached the success log below

Starting
Packet queued
313395: EV_JOINING
752319: EV_TXSTART: ch 1 rps=0x1 (SF7 BW125 CR 4/5 Crc IH=0), datarate 5, opmode 88C
1060694: EV_RXSTART: freq=865.4 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 756222, delta ms 4871
1113177: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 756222, delta ms 5711
1153244: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
1477698: EV_TXSTART: ch 2 rps=0x1 (SF7 BW125 CR 4/5 Crc IH=0), datarate 5, opmode 88C
1786073: EV_RXSTART: freq=865.9 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 1481601, delta ms 4871
1838556: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 1481601, delta ms 5711
1878622: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
2091308: EV_TXSTART: ch 0 rps=0x1 (SF7 BW125 CR 4/5 Crc IH=0), datarate 5, opmode 88C
2399682: EV_RXSTART: freq=865.0 rps=0x81 (SF7 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 2095211, delta ms 4871
2452166: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 5, opmode 88C, txend 2095211, delta ms 5711
2492234: EV_JOIN_TXCOMPLETE: saveIrqFlags 0x80
3498319: EV_TXSTART: ch 1 rps=0x2 (SF8 BW125 CR 4/5 Crc IH=0), datarate 4, opmode 88C
3802386: EV_RXSTART: freq=865.4 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 88C, txend 3505435, delta ms 4751
3823717: EV_JOINED: ch 1
netid: 19
devaddr: 2601255D
artKey: C9-DA-D6-B6-4A-0-77-9D-B6-9D-C0-F2-48-62-CB-E4
nwkKey: 53-E0-83-E6-83-A0-15-55-F7-EE-88-3A-B0-9D-67-2F
3823851: EV_TXSTART: ch 0 rps=0x2 (SF8 BW125 CR 4/5 Crc IH=0), datarate 4, opmode 888
3890463: EV_RXSTART: freq=865.0 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 888, txend 3830967, delta ms 951
3950467: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 888, txend 3830967, delta ms 1912
4234028: EV_TXCOMPLETE: ch 0 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0) txrxflags 0x20
Packet queued
4546662: EV_TXSTART: ch 1 rps=0x2 (SF8 BW125 CR 4/5 Crc IH=0), datarate 4, opmode 888
4613276: EV_RXSTART: freq=865.4 rps=0x82 (SF8 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 888, txend 4553780, delta ms 951
4673280: EV_RXSTART: freq=866.5 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0), datarate 4, opmode 888, txend 4553780, delta ms 1912
4982624: EV_TXCOMPLETE: ch 1 rps=0x84 (SF10 BW125 CR 4/5 NoCrc IH=0) txrxflags 0x20

I will experiment more.
We can close this ticket.

@terrillmoore
Copy link
Member

That's reassuring. Thanks.

@terrillmoore terrillmoore added question and removed bug labels May 6, 2019
@cyberman54
Copy link

@svelmurugan92 @terrillmoore I'm fighting the same symptom for a long time, including current LMIC (852f348), testing on EU868 with TTNv2.

See my issue #455

Some days no joins at all, last days smooth join, and these days "EV_JOIN_TXCOMPLETE" again.

No clue where to look at.

@svelmurugan92
Copy link
Author

@cyberman54 Which board are you using? I normally use India band which is very similar to EU.
I will try to setup the device in EU band and check.

@terrillmoore
Copy link
Member

Seems like we should reopen this for now

@terrillmoore terrillmoore reopened this Sep 18, 2019
@cyberman54
Copy link

cyberman54 commented Sep 19, 2019 •
edited
Loading

@svelmurugan92 i'm using ESP32, running my app on arduino-esp32 stack.

@terrillmoore meanwhile i managed to write logs

  • on my 2 gateways (1 TTIG, 1 MatchX)
  • on TTN console
  • on LMIC client

while the device repeatedly reports the "EV_JOIN_TXCOMPLETE" event.

I turned out, that in this situation there was no JOIN ACCEPT packet sent by both gateways, according to the gateway logs. While this is happening, TTN gateway console shows the yellow join request packet, but no green join accept packet.

So this seems a TTN network related issue. For some reason, sometimes (when?) or on certain conditions (which?) join accept packets seem not to be answered by the network. Thus, the behaviour of LMIC is correct.

@DaveDavenport
Copy link

DaveDavenport commented Nov 20, 2019 •
edited
Loading

I am hit by this same issue, it often takes days to successfully connect.

Weirdly enough I have some old code that does work using: https://github.com/matthijskooijman/arduino-lmic (on same hardware).

Any suggestions on what I can do to debug this issue?

  • I am on the latest git version.
  • stm32 (blue pill).
  • EU region.
  • Tried using interrupts and no interrupts.
  • tried with/without debug enabled.
  • I do see the yellow join requests in TTN console.
  • tried different clockerror settings.

I regrettably do not have my own gateway, so cannot grab logs from that.

@terrillmoore
Copy link
Member

HI @DaveDavenport. Sorry, this one is my fault. During cert testing I ran into a problem with data reliability. I looked into the code and found that the LMIC was using radically different timing parameters than Semtech. This is issue #442.

When I applied this change, I didn't realize that in fact RX for SF12 was adversely affected. I am planning to set up a test jig this weekend, and hope to finally characterize this. (I have test equipment, but nothing that will give me a GPIO signal at the start and end of the downlink TX, so I can match to my downlink RX.)

Unfortunately, joins in EU use SF12.

You can revert to an older LMIC, or try backing out the changes around #442. The changeset is 42da75b. This will reduce your overall RX quality, but will make SF12 (specifically) work beter.

@DaveDavenport
Copy link

Thanks, will try.

@cyberman54
Copy link

@DaveDavenport If you work out a patch, please let us know here. I am facing the same problem since weeks.

@DaveDavenport
Copy link

I reverted my checkout to the commit before: 42da75b. This worked-ish for me.

@cyberman54
Copy link

cyberman54 commented Nov 21, 2019 •
edited
Loading

I reverted my checkout to the commit before: 42da75b. This worked-ish for me

@DaveDavenport Do you have a fork online which is in current HEAD level of MCCI LMIC, but has the above changeset/commit reverted?

@DaveDavenport
Copy link

why would you make a fork? its a single command to get the right checkout?

@terrillmoore terrillmoore mentioned this issue Dec 26, 2019
Closed
@DaveDavenport
Copy link

Any update on this issue?

@terrillmoore
Copy link
Member

terrillmoore commented Jan 5, 2020 •
edited
Loading

@DaveDavenport I have committed a number of changes to head; they resolved the device-specific SF12 issues that I was seeing. I've had no feedback from testers (positive or negative). I ran the full EU868 pre-compliance test with the RWC5020, and everything worked well. But... others may have different experiences. I don't have resources to do commercial-scale testing. The problems were related to timing. I added features to https://github.com/mcci-catena/rwc_nst_test that allowed me to sweep the window, and I observed interesting reliability problems related to grounding; on a hunch, I moved the window opening earlier. It helped for me.

One thing that's clear: your platform must have access to a reasonably accurate time base. Some devices, like the Murata module, use an oscillator that's only 4000ppm accurate. The LoRaWAN spec practically requires 100ppm accuracy, and the Semtech and mbed sample code assume that accxuracy. The LMIC can accommodate 4000ppm for class A, but this appears to require using a different RX windowing scheme than Semtech uses.

See lengthy discussion starting at #483 (comment).

@DaveDavenport
Copy link

thx.

@DaveDavenport
Copy link

I can confirm that that master allows me to connect and send a message..

@terrillmoore
Copy link
Member

@DaveDavenport excellent, thanks so much for testing. What radio/CPU, network, and region are you using?

@DaveDavenport
Copy link

RFM95W module.. uses SX1276 I think connected to a blue pill (stm32f108).

On EU network. 868 MHz.
data rate: SF10BW125
coding rate: 4/5

Using the things network

@terrillmoore
Copy link
Member

terrillmoore commented Jan 5, 2020 •
edited
Loading

Great, thanks very much. There's some test diversity, as I'm using (primarily) Murata modules. And I don't have a live EU network to test against, just the network simulator that's part of the RWC5020A.

@DaveDavenport
Copy link

I am completely new to this, I bought some units to play around.

@terrillmoore
Copy link
Member

Welcome to the party, have fun!

blueish4 pushed a commit to blueish4/IndividualProject-device that referenced this issue Jan 13, 2020
debugging join failure
65c0f00 
 see mcci-catena/arduino-lmic#311
@DaveDavenport
Copy link

It seems to be running pretty reliable. Better then I had this/other libs running before.

@terrillmoore
Copy link
Member

Excellent, thanks for letting me know.

@cyberman54
Copy link

To be more precise on my testing results:

  • tested china boards with HOPE RF modules, some acting as SX1276, some as SX1272
  • working on Arduino ESP32 platform, on top of FreeRTOS multitasking environment
  • LMIC stack running in dedicated task on core1 ("App CPU" in Arduino ESP32 framework)
  • task priority 2
  • on EU network 868 MHz, using TTN
  • different gateways (Kerlink Wirnet, RAK7258, TTIG, Tektelic)

After devices join, stable transmissions, no issues.
Joins delays seem still to be random:

  • sometimes devices connect very fast on SF7BW125,
  • sometimes it takes several minutes while LMIC is escalating the SF, mostly until SF10.

Chance that devices join immediately when trying a bunch of joins is around 30%.

@ifrew
Copy link

ifrew commented Jun 8, 2020

Hi Folks,

I just started moving up the stack from developing lora apps working at the physical layer over the last couple of years. Last couple of days I started using Lorawan and the MCCI LMIC library. As per the instructions which were really clear, I managed to get my TTGO TBeam board running the TTN-ABP example and sending data to The Things Network. So feeing happy I moved up to use the OTTA-TTN example as per the recommendations. I am using the latest libraries as of today and I am now getting the "EV_JOIN_TXCOMPLETE" event repeatedly. Has their been a regression n the OTTA code? I should also say I'm in the USA using the CFG_us915 configuration and the "bad" workaround of disabling all subbands and then enabling just one channel.. Working up the stack incrementally.

Any thoughts?

EV_JOIN_TXCOMPLETE.txt

@DaveDavenport
Copy link

Hi Folks,

I just started moving up the stack from developing lora apps working at the physical layer over the last couple of years. Last couple of days I started using Lorawan and the MCCI LMIC library. As per the instructions which were really clear, I managed to get my TTGO TBeam board running the TTN-ABP example and sending data to The Things Network. So feeing happy I moved up to use the OTTA-TTN example as per the recommendations. I am using the latest libraries as of today and I am now getting the "EV_JOIN_TXCOMPLETE" event repeatedly. Has their been a regression n the OTTA code? I should also say I'm in the USA using the CFG_us915 configuration and the "bad" workaround of disabling all subbands and then enabling just one channel.. Working up the stack incrementally.

Any thoughts?

EV_JOIN_TXCOMPLETE.txt

regrettable for me it has been pretty hit and miss. Once connected it works well, but it sometimes takes days to connect othertimes it is really quick. I kinda gave up for now and shelved my project.

@DaveDavenport DaveDavenport mentioned this issue Jun 23, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@svelmurugan92 svelmurugan92

@terrillmoore terrillmoore

Labels
question
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@DaveDavenport @cyberman54 @ifrew @svelmurugan92 @terrillmoore