cyberman54 / ESP32-Paxcounter

Wifi & BLE driven passenger flow metering with cheap ESP32 boards
https://cyberman54.github.io/ESP32-Paxcounter/
Other
1.74k stars 407 forks source link

HELTEC LORA 32 V2 - OTAA join fails #411

Closed FrankUlbrich closed 5 years ago

FrankUlbrich commented 5 years ago

Hi cyberman I need support to get PAXCOUNTER jointed via OTAA. HELTEC Lora 32 V2. 10m away from the Lora 8 chanel gateway.

The join works by using a OTAA demo sketch after some seconds. The demo sketch is compiled with ARDUINO 1.8.5 / LMIC 1.5.0+arduino2 library. (https://github.com/matthijskooijman/arduino-lmic)

The join of PAXCOUNTER does not working in my case. In the file of Loraserver the request is recorded and the positive reponse is sent. It looks like that this response is not recognized by the node.

Can you see something in the Logs which may help to find the failure ?

PAXCNT v1.7.841

I][main.cpp:134] setup(): Starting PAXCNT v1.7.841
[I][main.cpp:147] setup(): This is ESP32 chip with 2 CPU cores, WiFi/BT/BLE, silicon revision 1, 8MB external Flash
[I][main.cpp:149] setup(): Internal Total heap 274144, internal Free Heap 248168
[I][main.cpp:155] setup(): ChipRevision 1, Cpu Freq 240, SDK Version v3.2-18-g977854975
[I][main.cpp:157] setup(): Flash Size 8388608, Flash Speed 40000000
[I][main.cpp:158] setup(): Wifi/BT software coexist version 1.1.5
[I][main.cpp:162] setup(): IBM LMIC version 1.6.1468577746
[I][main.cpp:167] setup(): Arduino LMIC version 2.3.2.51
[I][macsniff.cpp:36] printKey(): DevEUI: 00EC094D04299F02
[I][macsniff.cpp:36] printKey(): AppEUI: 70B3D57ED0020457
[I][macsniff.cpp:36] printKey(): AppKey: C4154AE996751303B6691E0D43AF65DA
[I][configmanager.cpp:185] loadConfig(): Reading settings from NVS
[I][configmanager.cpp:50] open_storage(): Opening NVS
[I][configmanager.cpp:55] open_storage(): Done
[I][configmanager.cpp:199] loadConfig(): NVRAM settings version = 1.7.841
[I][configmanager.cpp:217] loadConfig(): bsecstate = 0
[I][configmanager.cpp:222] loadConfig(): lorasf = 9
[I][configmanager.cpp:230] loadConfig(): txpower = 15
[I][configmanager.cpp:238] loadConfig(): adrmode = 1
[I][configmanager.cpp:246] loadConfig(): screensaver = 0
[I][configmanager.cpp:254] loadConfig(): screenon = 1
[I][configmanager.cpp:262] loadConfig(): countermode = 0
[I][configmanager.cpp:270] loadConfig(): sendcycle = 30
[I][configmanager.cpp:278] loadConfig(): wifichancycle = 50
[I][configmanager.cpp:286] loadConfig(): wifiantenna = 0
[I][configmanager.cpp:294] loadConfig(): vendorfilter = 1
[I][configmanager.cpp:302] loadConfig(): rgbluminosity = 30
[I][configmanager.cpp:310] loadConfig(): blescantime = 8
[I][configmanager.cpp:318] loadConfig(): BLEscanmode = 0
[I][configmanager.cpp:326] loadConfig(): rssilimit = 0
[I][configmanager.cpp:334] loadConfig(): payloadmask = 255
[I][configmanager.cpp:342] loadConfig(): Monitor mode = 0
[I][configmanager.cpp:350] loadConfig(): Run mode = 0
[I][configmanager.cpp:357] loadConfig(): Done
[I][main.cpp:215] setup(): Starting LED Controller...
[I][lorawan.cpp:424] lora_stack_init(): LORA send queue created, size 530 Bytes
[I][lorawan.cpp:426] lora_stack_init(): Starting LMIC...
RXMODE_RSSI
[I][main.cpp:359] setup(): Starting Interrupt Handler...
[I][main.cpp:389] setup(): Starting Timers...
[I][main.cpp:455] setup(): Starting Timekeeper...
[I][timekeeper.cpp:105] timepulse_init(): Timepulse: internal (ESP32 hardware timer)
[I][timesync.cpp:41] send_timesync_req(): [4.959] Timeserver sync request started
[I][main.cpp:462] setup(): Features: VEXT LED LORA FILTER OLED PACKED BTN_PD
[I][lorawan.cpp:339] onEvent(): JOINING
311037: engineUpdate, opmode=0x4
405003: engineUpdate, opmode=0x4
405188: TXMODE, freq=868100000, len=23, SF=7, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 5
713665: RXMODE_SINGLE, freq=868100000, SF=7, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 16
768734: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 815832 rxtime: 768693 entry-rxtime: 47139 now-entry: 7 rxtime-txend: 359640
[I][lorawan.cpp:339] onEvent(): JOIN WAIT
815916: engineUpdate, opmode=0x4
4519143: engineUpdate, opmode=0x4
4519320: TXMODE, freq=868300000, len=23, SF=7, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 9
4827814: RXMODE_SINGLE, freq=868300000, SF=7, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 8
4882849: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 4929955 rxtime: 4882825 entry-rxtime: 47130 now-entry: 13 rxtime-txend: 359640
[I][lorawan.cpp:339] onEvent(): JOIN WAIT
4930065: engineUpdate, opmode=0x4
8845278: engineUpdate, opmode=0x4
8845450: TXMODE, freq=868500000, len=23, SF=7, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 9
9153930: RXMODE_SINGLE, freq=868500000, SF=7, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 3
9208968: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 9256085 rxtime: 9208955 entry-rxtime: 47130 now-entry: 7 rxtime-txend: 359640
[I][lorawan.cpp:339] onEvent(): JOIN WAIT
9256176: engineUpdate, opmode=0x4
13293364: engineUpdate, opmode=0x4
13293532: TXMODE, freq=868100000, len=23, SF=8, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 3
13597711: RXMODE_SINGLE, freq=868100000, SF=8, BW=125, CR=4/5, IH=0
rxtimeout: entry: 13629588 rxtime: 13597689 entry-rxtime: 31899 now-entry: 12 rxtime-txend: 297076
start single rx: now-rxtime: 9
13660271: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 13707389 rxtime: 13660253 entry-rxtime: 47136 now-entry: 7 rxtime-txend: 359640
[I][lorawan.cpp:339] onEvent(): JOIN WAIT
13707490: engineUpdate, opmode=0x4
20982368: engineUpdate, opmode=0x4
20982534: TXMODE, freq=868300000, len=23, SF=8, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 9
21286726: RXMODE_SINGLE, freq=868300000, SF=8, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 3
21349269: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 21396386 rxtime: 21349256 entry-rxtime: 47130 now-entry: 8 rxtime-txend: 359640
[I][lorawan.cpp:339] onEvent(): JOIN WAIT
21396504: engineUpdate, opmode=0x4
28894753: engineUpdate, opmode=0x4
28894926: TXMODE, freq=868500000, len=23, SF=8, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 8
29199109: RXMODE_SINGLE, freq=868500000, SF=8, BW=125, CR=4/5, IH=0
start single rx: now-rxtime: 9
29261665: RXMODE_SINGLE, freq=869525000, SF=12, BW=125, CR=4/5, IH=0
rxtimeout: entry: 29308778 rxtime: 29261647 entry-rxtime: 47131 now-entry: 7 rxtime-txend: 359640
[I][lorawan.cpp:339] onEvent(): JOIN WAIT
29308881: engineUpdate, opmode=0x4

JOIN REQUEST

{
  "gw_id": "eui-b827ebfffe164cc5",
  "payload": "AFcEAtB+1bNwAp8pBE0J7ADxCsfaVMY=",
  "dev_eui": "00EC094D04299F02",
  "lora": {
    "spreading_factor": 9,
    "bandwidth": 125,
    "air_time": 205824000
  },
  "coding_rate": "4/5",
  "timestamp": "2019-08-13T19:10:13.580Z",
  "rssi": -74,
  "snr": 7.2,
  "app_eui": "70B3D57ED0020457",
  "frequency": 868500000
}

JOIN ACCEPT

{
  "gw_id": "eui-b827ebfffe164cc5",
  "payload": "AFcEAtB+1bNwAp8pBE0J7ADyCrdKbUg=",
  "dev_eui": "00EC094D04299F02",
  "lora": {
    "spreading_factor": 9,
    "bandwidth": 125,
    "air_time": 205824000
  },
  "coding_rate": "4/5",
  "timestamp": "2019-08-13T19:14:01.247Z",
  "rssi": -77,
  "snr": 9.2,
  "app_eui": "70B3D57ED0020457",
  "frequency": 868100000
}

Do you think there may be a way to get it working ? It would be nice if you find a solution for me.

Best regards from Krefeld, Germany --- Frank

FrankUlbrich commented 5 years ago

Just one more testing: If I compile and flash the code into "TTGO T_BEAM" it works. I have just problems with the "HELTEC LoRa 32 v.2."

Best regards Frank

cyberman54 commented 5 years ago

I saw this with other boards, too. Not sure if this an LMiC stack related issue. Could be a timing issue which is related to run the LMiC stack in multitasking environment of paxcounter. Could be a hardware issue related to wiring / signalling of DIO1 line to GPIO port of ESP32.

Can you please try this and report results here: Trial No. 1: Use current version 1.9.x from development branch. In this version i made significant changes to the multitasking which will affect timing in LMiC stack. Please report if you see a difference in join behaviour.

Trial No. 2: in lmic_config.h change line #define CLOCK_ERROR_PROCENTAGE 5 to value 7

FrankUlbrich commented 5 years ago

My working demo sketch

/*******************************************************************************
 * Copyright (c) 2015 Thomas Telkamp and Matthijs Kooijman
 *
 * Permission is hereby granted, free of charge, to anyone
 * obtaining a copy of this document and accompanying files,
 * to do whatever they want with them without any restriction,
 * including, but not limited to, copying, modification and redistribution.
 * NO WARRANTY OF ANY KIND IS PROVIDED.
 *
 * This example sends a valid LoRaWAN packet with payload "Hello,
 * world!", using frequency and encryption settings matching those of
 * the The Things Network.
 *
 * This uses OTAA (Over-the-air activation), where where a DevEUI and
 * application key is configured, which are used in an over-the-air
 * activation procedure where a DevAddr and session keys are
 * assigned/generated for use with all further communication.
 *
 * Note: LoRaWAN per sub-band duty-cycle limitation is enforced (1% in
 * g1, 0.1% in g2), but not the TTN fair usage policy (which is probably
 * violated by this sketch when left running for longer)!

 * To use this sketch, first register your application and device with
 * the things network, to set or generate an AppEUI, DevEUI and AppKey.
 * Multiple devices can use the same AppEUI, but each device has its own
 * DevEUI and AppKey.
 *
 * Do not forget to define the radio type correctly in config.h.
 *
 *******************************************************************************/

/* ARDUINO IDE 1.8.3
 * 
 * Hardware : Heltec Lora 32 V2
 * Freq: 868MhZ 
 */

#include <lmic.h>              // IBM lmic 1.5.0+arduino-2 
#include <hal/hal.h>
#include <SPI.h>

// This EUI must be in little-endian format, so least-significant-byte
// first. When copying an EUI from ttnctl output, this means to reverse
// the bytes. For TTN issued EUIs the last bytes should be 0xD5, 0xB3,
// 0x70.
// LSB
static const u1_t PROGMEM APPEUI[8]={ 0x2E, 0x09, 0x02, ............, 0x70 };
void os_getArtEui (u1_t* buf) { memcpy_P(buf, APPEUI, 8);}

// This should also be in little endian format, see above.
// LSB
static const u1_t PROGMEM DEVEUI[8]={ 0xEF, 0x71, ........ };
void os_getDevEui (u1_t* buf) { memcpy_P(buf, DEVEUI, 8);}

// This key should be in big endian format (or, since it is not really a
// number but a block of memory, endianness does not really apply). In
// practice, a key taken from ttnctl can be copied as-is.
// The key shown here is the semtech default key.
// MSB
static const u1_t PROGMEM APPKEY[16] = { 0x64, ...... 0x43, 0xB0, 0x78 };
void os_getDevKey (u1_t* buf) {  memcpy_P(buf, APPKEY, 16);}

static uint8_t mydata[] = "Hello, world!";
static osjob_t sendjob;

// Schedule TX every this many seconds (might become longer due to duty
// cycle limitations).
const unsigned TX_INTERVAL = 22;

//LMIC LoRa module pin configuration
//For Heltec Wifi LoRa 32 v2
const lmic_pinmap lmic_pins = {
    .nss = 18, 
    .rxtx = LMIC_UNUSED_PIN,
    .rst = 14,
    //.dio = {/*dio0*/ 26, /*dio1*/ 34, /*dio2*/ 35}     // working with HELTEC Loro 32 v.2
    .dio = {/*dio0*/ 26, /*dio1*/ 35, /*dio2*/ 34}       // working with HELTEC Lora 32 v2. (HELTEC Doku)
};

// Pin mapping GITHUB HELTEC
/* #if defined(V1)
const lmic_pinmap lmic_pins = {
    .nss = 18,
    .rxtx = LMIC_UNUSED_PIN,
    .rst = 14,
    .dio = {26, 33, 32},
};
#elif defined(V2)
const lmic_pinmap lmic_pins = {
    .nss = 18,
    .rxtx = LMIC_UNUSED_PIN,
    .rst = 14,
    .dio = {26, 35, 34},
}; */

void onEvent (ev_t ev) {
    Serial.print(os_getTime());
    Serial.print(": ");
    switch(ev) {
        case EV_SCAN_TIMEOUT:
            Serial.println(F("EV_SCAN_TIMEOUT"));
            break;
        case EV_BEACON_FOUND:
            Serial.println(F("EV_BEACON_FOUND"));
            break;
        case EV_BEACON_MISSED:
            Serial.println(F("EV_BEACON_MISSED"));
            break;
        case EV_BEACON_TRACKED:
            Serial.println(F("EV_BEACON_TRACKED"));
            break;
        case EV_JOINING:
            Serial.println(F("EV_JOINING"));
            break;
        case EV_JOINED:
            Serial.println(F("EV_JOINED"));

            // Disable link check validation (automatically enabled
            // during join, but not supported by TTN at this time).
            LMIC_setLinkCheckMode(0);
            break;
        case EV_RFU1:
            Serial.println(F("EV_RFU1"));
            break;
        case EV_JOIN_FAILED:
            Serial.println(F("EV_JOIN_FAILED"));
            break;
        case EV_REJOIN_FAILED:
            Serial.println(F("EV_REJOIN_FAILED"));
            break;
            break;
        case EV_TXCOMPLETE:
            Serial.println(F("EV_TXCOMPLETE (includes waiting for RX windows)"));
            if (LMIC.txrxFlags & TXRX_ACK)
              Serial.println(F("Received ack"));
            if (LMIC.dataLen) {
              Serial.println(F("Received "));
              Serial.println(LMIC.dataLen);
              Serial.println(F(" bytes of payload"));
            }
            // Schedule next transmission
            os_setTimedCallback(&sendjob, os_getTime()+sec2osticks(TX_INTERVAL), do_send);
            break;
        case EV_LOST_TSYNC:
            Serial.println(F("EV_LOST_TSYNC"));
            break;
        case EV_RESET:
            Serial.println(F("EV_RESET"));
            break;
        case EV_RXCOMPLETE:
            // data received in ping slot
            Serial.println(F("EV_RXCOMPLETE"));
            break;
        case EV_LINK_DEAD:
            Serial.println(F("EV_LINK_DEAD"));
            break;
        case EV_LINK_ALIVE:
            Serial.println(F("EV_LINK_ALIVE"));
            break;
         default:
            Serial.println(F("Unknown event"));
            break;
    }
}

void do_send(osjob_t* j){
    // Check if there is not a current TX/RX job running
    if (LMIC.opmode & OP_TXRXPEND) {
        Serial.println(F("OP_TXRXPEND, not sending"));
    } else {
        // Prepare upstream data transmission at the next possible time.
        LMIC_setTxData2(1, mydata, sizeof(mydata)-1, 0);
        Serial.println(F("Packet queued"));
    }
    // Next TX is scheduled after TX_COMPLETE event.
}

void setup() {
    Serial.begin(115200);
    Serial.println(F("ttn-otaa"));
    Serial.println(F("Starting"));

    #ifdef VCC_ENABLE
    // For Pinoccio Scout boards
    pinMode(VCC_ENABLE, OUTPUT);
    digitalWrite(VCC_ENABLE, HIGH);
    delay(1000);
    #endif

    // LMIC init
    os_init();
    // Reset the MAC state. Session and pending data transfers will be discarded.
    LMIC_reset();

    // Start job (sending automatically starts OTAA too)  
    do_send(&sendjob);
}

void loop() {
    os_runloop_once();
}

Hallo cyberman, thanks for your answer, I will test your two trial mentioned above.

cyberman54 commented 5 years ago

I know the original LMiC library, but the MCCI fork is much better maintained and has lots of bug fixes.

FrankUlbrich commented 5 years ago
Trial No. 2: in lmic_config.h change line
#define CLOCK_ERROR_PROCENTAGE 7

It works with the master code and the setting above ad hoc with my "HELTEC LorA 32 V2" It joins immediatelly.

cyberman54 commented 5 years ago

did it not work with the dev version?

FrankUlbrich commented 5 years ago

I tested the PAXCOUNTER Version from your development tree : 1.7.91 It works without modifying "CLOCK_ERROR_PROCENTAGE 5"

Thank you very much for your support !

--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
[I][main.cpp:131] setup(): Starting PAXCNT v1.7.91
[I][main.cpp:144] setup(): This is ESP32 chip with 2 CPU cores, WiFi/BT/BLE, silicon revision 1, 8MB external Flash
[I][main.cpp:146] setup(): Internal Total heap 265436, internal Free Heap 239228
[I][main.cpp:152] setup(): ChipRevision 1, Cpu Freq 240, SDK Version v3.2-18-g977854975
[I][main.cpp:154] setup(): Flash Size 8388608, Flash Speed 40000000
[I][main.cpp:155] setup(): Wifi/BT software coexist version 1.1.5
[I][main.cpp:159] setup(): IBM LMIC version 1.6.1468577746
[I][main.cpp:164] setup(): Arduino LMIC version 2.3.2.51
[I][macsniff.cpp:36] printKey(): DevEUI: 00EC094D04299F02
[I][macsniff.cpp:36] printKey(): AppEUI: 70B3D57ED0020457
[I][macsniff.cpp:36] printKey(): AppKey: C4154AE996751303B6691E0D43AF65DA
[I][configmanager.cpp:185] loadConfig(): Reading settings from NVS
[I][configmanager.cpp:50] open_storage(): Opening NVS
[I][configmanager.cpp:55] open_storage(): Done
[I][configmanager.cpp:199] loadConfig(): NVRAM settings version = 1.7.91
[I][configmanager.cpp:217] loadConfig(): bsecstate = 0
[I][configmanager.cpp:222] loadConfig(): lorasf = 9
[I][configmanager.cpp:230] loadConfig(): txpower = 15
[I][configmanager.cpp:238] loadConfig(): adrmode = 1
[I][configmanager.cpp:246] loadConfig(): screensaver = 0
[I][configmanager.cpp:254] loadConfig(): screenon = 1
[I][configmanager.cpp:262] loadConfig(): countermode = 0
[I][configmanager.cpp:270] loadConfig(): sendcycle = 30
[I][configmanager.cpp:278] loadConfig(): wifichancycle = 50
[I][configmanager.cpp:286] loadConfig(): wifiantenna = 0
[I][configmanager.cpp:294] loadConfig(): vendorfilter = 1
[I][configmanager.cpp:302] loadConfig(): rgbluminosity = 30
[I][configmanager.cpp:310] loadConfig(): blescantime = 8
[I][configmanager.cpp:318] loadConfig(): BLEscanmode = 0
[I][configmanager.cpp:326] loadConfig(): rssilimit = 0
[I][configmanager.cpp:334] loadConfig(): payloadmask = 255
[I][configmanager.cpp:342] loadConfig(): Monitor mode = 0
[I][configmanager.cpp:350] loadConfig(): Run mode = 0
[I][configmanager.cpp:357] loadConfig(): Done
[I][main.cpp:212] setup(): Starting LED Controller...
[I][lorawan.cpp:425] lora_stack_init(): LORA send queue created, size 530 Bytes
[I][lorawan.cpp:428] lora_stack_init(): Starting LMIC...
[I][lorawan.cpp:340] onEvent(): JOINING
[I][main.cpp:342] setup(): Starting Wifi...
I (4954) wifi: wifi driver task: 3ffc3ac0, prio:23, stack:3584, core=0
I (10079) wifi: wifi firmware version: 6d404d4
I (10081) wifi: config NVS flash: disabled
I (10085) wifi: config nano formating: disabled
I (10090) wifi: Init dynamic tx buffer num: 32
I (10093) wifi: Init data frame dynamic rx buffer num: 10
I (10098) wifi: Init management frame dynamic rx buffer num: 10
I (10104) wifi: Init static rx buffer size: 1600
I (10108) wifi: Init static rx buffer num: 8
I (10112) wifi: Init dynamic rx buffer num: 10
I (10117) wifi: set country: cc=EU␀ schan=1 nchan=13 policy=1

W (10122) wifi: ap start fail

I (10179) wifi: ic_enable_sniffer
[I][main.cpp:356] setup(): Starting Interrupt Handler...
[I][main.cpp:378] setup(): Starting Timers...
[I][main.cpp:438] setup(): Starting Timekeeper...
[I][timekeeper.cpp:100] timepulse_init(): Timepulse: internal (ESP32 hardware timer)
[I][timesync.cpp:41] send_timesync_req(): [5.071] Timeserver sync request started
[I][timesync.cpp:252] setMyTime(): [5.079] Timesync failed, invalid time fetched | source: ?
[I][main.cpp:445] setup(): Features: VEXT LED OTA LORA FILTER OLED PACKED WIFI BTN_PD
[I][lorawan.cpp:224] onEvent(): DEVaddr=26012928
[I][lorawan.cpp:340] onEvent(): JOINED
[I][lorawan.cpp:340] onEvent(): TX TIMESYNC
[I][lorawan.cpp:403] lora_send(): 1 byte(s) sent to LoRa
[I][lorawan.cpp:340] onEvent(): TX COMPLETE 

I tested it 2 minutes ago.

Nette Grüße Frank