search

jeelabs / esp-link

esp8266 wifi-serial bridge, outbound TCP, and arduino/AVR/LPC/NXP programmer
Other
2.86k stars 727 forks source link

Getting corrupted debug lines with data. Using mqtt and udp leads to esp reboot. #390

Open leodesigner opened 6 years ago

leodesigner commented 6 years ago

Hi, I am sending udp data via el-client. Here is the debug info

696889> SLIP: start or end len=0 inpkt=1
696889> SLIP: start or end len=30 inpkt=1
696890> cmdParsePacket: cmd=41 argc=2 value=1
696890> cmdExec: Dispatching cmd=SOCKET_SEND
696890> SOCKET #1: send dataLen=6 socketData= 0,999�?@��?`
696890> SOCKET #1: Create connection to ip 10.0.1.3:10100
696890> SOCKET #1: sending 6 bytes:  0,999�?@��?`
696899> SLIP: start or end len=0 inpkt=1
696899> SLIP: start or end len=30 inpkt=1
696900> cmdParsePacket: cmd=41 argc=2 value=1
696900> cmdExec: Dispatching cmd=SOCKET_SEND
696900> SOCKET #1: send dataLen=6 socketData= 0,999�?@��?`
696900> SOCKET #1: Create connection to ip 10.0.1.3:10100
696900> SOCKET #1: sending 6 bytes:  0,999�?@��?`
696909> SLIP: start or end len=0 inpkt=1
696909> SLIP: start or end len=30 inpkt=1
696910> cmdParsePacket: cmd=41 argc=2 value=1
696910> cmdExec: Dispatching cmd=SOCKET_SEND
696910> SOCKET #1: send dataLen=6 socketData= 0,999�?@��?`
696910> SOCKET #1: Create connection to ip 10.0.1.3:10100
696910> SOCKET #1: sending 6 bytes:  0,999�?@��?`

Test string is " 0,999". Seems like it is not affecting actual data sent to the UDP socket, but after 200-300 udp messages eep-link stops sending data via UDP at all. Serial console is also blocked. Trying to get into this issue, does anybody had a stability issues with SLIP ? As soon as I am turning off SLIP, console is very stable back again.

uzi18 commented 6 years ago

More info needed - what version of esp-link and ELClient? test code, to reproduce etc.

leodesigner commented 6 years ago

Both are the latest versions (master branch). For now it's a part of a bigger codebase, so I need to prepare something lite to reproduce.

leodesigner commented 6 years ago

Here is the code to reproduce. The eep-link rebooting itself after 200-300 messages sent. The bug os only can be reproduced when working with mqtt client and udp socket at the same time.


#include <Arduino.h>
#include <ELClient.h>
#include <ELClientSocket.h>
#include <ELClientMqtt.h>

#define   PIN_LED               PC13

const char* udpServer = "10.0.1.3";
uint16_t udpPort = 10111;

ELClient esp(&Serial, &Serial);
ELClientMqtt mqtt(&esp);
ELClientSocket udp(&esp);

// Timer value to send out data
uint32_t wait;
// Time to wait between sending out data
uint32_t waitTime;
// Flag for wifi connection
boolean wifiConnected = false;
boolean mqtt_connected = false;

// Callback when MQTT is connected
void mqttConnected(void* response) {
  Serial.println("MQTT connected!");
  mqtt_connected = true;
}

// Callback when MQTT is disconnected
void mqttDisconnected(void* response) {
  Serial.println("MQTT disconnected");
  mqtt_connected = false;
}

#define TEMP_STR_MAX    32
char str[TEMP_STR_MAX+1];

// Callback when an MQTT message arrives for one of our subscriptions
void mqttData(void* response) {
  ELClientResponse *res = (ELClientResponse *)response;

  Serial.print("Received: topic = ");
  res->popChar(str);
  Serial.println(str);
}

void mqttPublished(void* response) {
  Serial.println("MQTT published");
}

// Callback for UDP socket, called if data was sent or received
// Receives socket client number, can be reused for all initialized UDP socket connections
// !!! UDP doesn't check if the data was received or if the receiver IP/socket is available !!! You need to implement your own
// error control!
void udpCb(uint8_t resp_type, uint8_t client_num, uint16_t len, char *data) {
    Serial.println("udpCb is called");
    if (len > 0) { // sending complete (no confirmation that it was received!) or we received something
        if (resp_type == USERCB_SENT) {
            Serial.println("\tSent " + String(len) + " bytes over connection #" + String(client_num));
        } else if (resp_type == USERCB_RECV) {
            char recvData[len+1]; // Prepare buffer for the received data
            memcpy(recvData, data, len); // Copy received data into the buffer
            recvData[len] = '\0'; // Terminate the buffer with 0 for proper printout!

            Serial.println("\tReceived " + String(len) + " bytes over client#" + String(client_num));
            Serial.println("\tReceived: " + String(recvData));
        } else {
            Serial.println("Received invalid response type");
        }
    } else if (len < 0) { // negative result means there was a problem
        Serial.print(F("Send error: "));
        Serial.println(len);
    }
}

// Callback made from esp-link to notify of wifi status changes
// Here we print something out and set a global flag
void wifiCb(void *response) {
    ELClientResponse *res = (ELClientResponse*)response;
    if (res->argc() == 1) {
        uint8_t status;
        res->popArg(&status, 1);

        if(status == STATION_GOT_IP) {
            Serial.println(F("WIFI CONNECTED"));
            wifiConnected = true;
        } else {
            Serial.print(F("WIFI NOT READY: "));
            Serial.println(status);
            wifiConnected = false;
        }
    }
}

void setup() {
    delay(30);
    Serial.begin(460800,SERIAL_8E1);
    delay(10);
    Serial.println(F("EL-Client starting!"));
    Serial.println(F("EL-Client starting!"));
    Serial.println(F("EL-Client starting!"));

    // Blink Led 
    pinMode(PIN_LED,OUTPUT);
    digitalWrite(PIN_LED, HIGH);
    delay(70);
    digitalWrite(PIN_LED, LOW);
    delay(20);

    esp.wifiCb.attach(wifiCb); // wifi status change callback, optional (delete if not desired)
    bool ok;
    do {
        ok = esp.Sync();            // sync up with esp-link, blocks for up to 2 seconds
        if (!ok) Serial.println(F("EL-Client sync failed!"));
        digitalWrite(PIN_LED, HIGH);
        delay(20);
        digitalWrite(PIN_LED, LOW);
        delay(20);
    } while(!ok);
    Serial.println(F("EL-Client synced!"));

    esp.GetWifiStatus();
    ELClientPacket *packet;
    if ((packet=esp.WaitReturn()) != NULL) {
        Serial.print(F("Wifi status: "));
        Serial.println(packet->value);
    }

    int err = udp.begin(udpServer, udpPort, SOCKET_UDP, udpCb);
    if (err < 0) {
        Serial.print(F("UDP begin failed: "));
        Serial.println(err);
        delay(10000);
    }

    // Set-up callbacks for events and initialize with esp-link.
    mqtt.connectedCb.attach(mqttConnected);
    mqtt.disconnectedCb.attach(mqttDisconnected);
    mqtt.publishedCb.attach(mqttPublished);
    mqtt.dataCb.attach(mqttData);
    mqtt.setup();
    esp.Process();
    Serial.println("EL-MQTT ready");
    esp.Process();

    Serial.println(F("EL-Client ready!"));
    wait = millis()+29000; // Start first sending in 1 second
}

void loop() {
    // process any callbacks coming from esp_link
    esp.Process();

    // if we're connected send data over UDP socket
    if(wifiConnected) {
        if (millis() - wait > 20) {
                        wait = millis();
            Serial.print(F("Sending message to "));
            Serial.println(udpServer);
            udp.send("UDP Message...");
                        mqtt.publish("/tsttopic","SomeMQTTGoodie");
        }
    }
}
leodesigner commented 6 years ago

Couple of last console output lines before crash and reboot:

Sending message to 10.0.1.3
ELC: got 22 @20000BFC: 3 20000CDC 3 1 0 0 0 1 0 0 0 2 0 E 0 D 68
RESP_CB: 536874204 3
udpCb is called
    Sent 14 bytes over connection #0
Sending message to 10.0.1.3
ELC: got 22 @20000BFC: 3 20000CDC 3 1 0 0 0 1 0 0 0 2 0 E 0 D 68
RESP_CB: 536874204 3
udpCb is called
    Sent 14 bytes over connection #0
Sending message to 10.0.1.3
ELC: got 22 @20000BFC: 3 20000CDC 3 1 0 0 0 1 0 0 0 2 0 E 0 D 68
RESP_CB: 536874204 3
udpCb is called
    Sent 14 bytes over connection #0
Sending message to 10.0.1.3
ELC: got 22 @20000BFC: 3 20000CDC 3 1 0 0 0 1 0 0 0 2 0 E 0 D 68
RESP_CB: 536874204 3
udpCb is called
    Sent 14 bytes over connection #0
Sending message to 10.0.1.3
Sending message to 10.0.1.3
Sending message to 10.0.1.3
Sending message to 10.0.1.3
Sending message to 10.0.1.3
Sending message to 10.0.1.3

Seems last few lines no confirmation callback from udp send. So mqtt client and udp not playing well :(

nc -u -l 10.0.1.3 10111

UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Messag
e...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Me
ssage...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UD
P Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message.
..UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Mess
age...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP 
Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...
UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Messag
e...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Me
ssage...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UD
P Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message.
..UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Mess
age...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP 
Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...
UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Messag
e...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...UDP Message...

Reboot

uzi18 commented 6 years ago

And without mqtt publish is it ok?

leodesigner commented 6 years ago

Yes, I am looking now to the socket.c, found a couple of bugs. Seems nobody tested it when attached mcu is rebooted and it is trying to connect to the same udp remote.

leodesigner commented 6 years ago

Fixed some bugs in the socket.c (They are related to the creation of new sockets and checking already opened connections) https://github.com/leodesigner/esp-link/commit/8a59fac3168673f30af3be98a993525d3dacf27f And added some small useful feature to skip sent callback confirmation sending back to the MCU. I can prepare PR if it's useful.

Regarding the original issue, seems like ESP8266 cannot keep up with high data rate sending via mqtt, this is why I need to use some kind of udp->mqtt bridge additionally. (MQTT-SN ?).

uzi18 commented 6 years ago

nice work, what do You think @tve? try to send binary data by mqtt or split data into smaller packets.

leodesigner commented 6 years ago

Reverted some changes regarding the pointers to the structures (made a mistake :)), Added a couple of new features and bugfixes too. Got eep-link running at 1.5 Mbit/s with STM32f103. Welcome to test my fork at: https://github.com/leodesigner/esp-link

uzi18 commented 6 years ago

nice work :)

leodesigner commented 6 years ago

Thanks, still some improvements left to do.

uzi18 commented 6 years ago

why you use 1.5Mbit/s?

leodesigner commented 6 years ago

It's a realtime monitoring of PV solar array system. I needed a 10ms reports with minimum as possible delay/lag. So this is why UDP and 1.5 Mbit.

uzi18 commented 6 years ago

Are you using ELClient library or your own protocol?

niedz., 5.08.2018, 10:30 użytkownik leodesigner notifications@github.com napisał:

It's a realtime monitoring of PV solar array system. I needed a 10ms reports with minimum as possible delay/lag. So this is why UDP and 1.5 Mbit.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/jeelabs/esp-link/issues/390#issuecomment-410504623, or mute the thread https://github.com/notifications/unsubscribe-auth/AAHOUzxJCuD_qpabGwhmKw3XujSjrvlaks5uNq0vgaJpZM4UZaRq .

leodesigner commented 6 years ago

ELClient, UDP send. Still need to figure out what todo in case if no WiFi during mcu startup. Also the circular buffer overrun could be processed somehow better.