256dpi / arduino-mqtt

MQTT library for Arduino
MIT License
1.02k stars 236 forks source link

Disconnected after second msg. (SIM800L baud rate) #190

Closed ortegafernando closed 4 years ago

ortegafernando commented 4 years ago

HI, I go on checking this great library. Now I have checked to publish a msg every 60 seconds (Vcc), and compare with pubsubclient (just in case).

I get an strange behaviour with arduino-mqtt and I don't know where I have to start or continue with the debuging process.

My configuration is an Arduino Pro Mini + SIM800L + TinyGSM library. Suscribe and publish are QOS 0. And node red is also conifgured with QOS 0 Node red sends timestamp to swtich on/off led. Ardunio Pro Mini sends Vcc to nodered every minute.

This is my sketch (it is almost the usual example). As you could see I have already increased buffer to 256 (just in case, because with 128 has to be enough). Also I am using F("") in string to increase free ram in arduino (just in case)

Summary: 3 test and 3 logs

  1. pubsubclient: In this case I left the arduino to do its job. Send Vcc every minute. As you can see I get more than 4 msg with Vcc data. So everything is Ok See these seconds: 59: Vcc 122: Vcc 185: Vcc

  2. pubsubclient: In this case, I also send msg (timestamp) from Node red to arduino to switch on/off the led. Meanwhile, arduino is sending Vcc data. Everything is Ok. See these seconds. 59: Vcc 69: switch on/off led 86: switch on/off led 92: switch on/off led 120: switch on/off led 122: Vcc

  3. arduino-mqtt library: here we have a big log to test everything. It is a very long log but I will split it in three parts 3.1 first part is to see how MQTT disconnect after the second Vcc message. See these seconds: 59: Vcc 122: Vcc 125: MQTT DISCONNECT 185: Vcc 248: Vcc 251: MQTT DISCONNECT

3.2 second part is to see what happens when we send from Node Red a message to switch on/off the led. If we stop sending msg from node red, after the second Vcc data in a row, MQTT IS DISCONNECTED again. (see part 3.3) See these seconds: ----- end of part 3.1 and start of part 3.2 ------ 259: switch on/off led 265: switch on/off led 311: Vcc 373: Vcc 377: MQTT DISCONNECT 437: Vcc 445: switch on/off led 456: switch on/off led 468: switch on/off led 474: switch on/off led 500: Vcc 562: Vcc 566: MQTT DISCONNECT

3.3 I f we send a node red msg every time I get Vcc data, MQTT DON'T disconnect. But if we dont send anything from Nodered, after two Vcc msg in a row --> MQTT DISCONNECTs. See these seconds: ----- end of part 3.2 and start of part 3.3 ------ 625: Vcc 634: switch on/off led 688: Vcc 696: switch on/off led 751: Vcc 757: switch on/off led 814: Vcc 867: Vcc 879: MQTT DISCONNECT

I am getting crazy.

/**************************************************************
 *
 *   https://github.com/256dpi/arduino-mqtt
 *
 * TinyGSM Getting Started guide:
 *   https://tiny.cc/tinygsm-readme
 *
 **************************************************************/

#define PUBSUB  //use PubSubClient

// Select your modem:
#define TINY_GSM_MODEM_SIM800
//#define TINY_GSM_MODEM_SIM900

// See all AT commands, if wanted
//#define DUMP_AT_COMMANDS

// Set serial for debug console (to the Serial Monitor, default speed 115200)
#define SerialMon Serial

// Set serial for AT commands (to the module)
#include <SoftwareSerial.h>
SoftwareSerial SerialAT(8, 7); // RX, TX

// Define the serial console for debug prints, if needed
#define TINY_GSM_DEBUG SerialMon

// Range to attempt to autobaud
#define GSM_AUTOBAUD_MIN 2400
#define GSM_AUTOBAUD_MAX 9600

// Add a reception delay - may be needed for a fast processor at a slow baud rate
//#define TINY_GSM_YIELD() { delay(2); }

// Define how you're planning to connect to the internet
#define TINY_GSM_USE_GPRS true
#define TINY_GSM_USE_WIFI false

// set GSM PIN, if any
#define GSM_PIN ""

// Your GPRS credentials. Leave empty, if missing user or pass
const char apn[]  = "orangeworld";
const char gprsUser[] = "";
const char gprsPass[] = "";

// MQTT details
const char* broker = "XXXXXX.com";
const unsigned int port = 1883;

//Change this to avoid in test overflow in buffer
const char* topicLed = "gate/led";
const char* topicInit = "gate/init";
const char* topicLedStatus = "gate/ledStatus";
const char* topicVcc = "gate/vcc";

#include <TinyGsmClient.h>
#ifdef PUBSUB
  #include <PubSubClient.h>
#else
  #include <MQTT.h>
#endif

#ifdef DUMP_AT_COMMANDS
  #include <StreamDebugger.h>
  StreamDebugger debugger(SerialAT, SerialMon);
  TinyGsm modem(debugger);
#else
  TinyGsm modem(SerialAT);
#endif

TinyGsmClient client(modem);
#ifdef PUBSUB
  PubSubClient mqtt(client);
#else
  //MQTTClient mqtt;
  MQTTClient mqtt(256);   //Just in case, increase buffer
#endif

#define LED_PIN 13
int ledStatus = LOW;
unsigned long lastReconnectAttempt = 0;

//Vcc
unsigned long lastVcc = 0;
const unsigned long loopVcc = 60000;  //Send every 60 seconds

boolean msg4ledStatus = false;  //200203: It is better not to publish inside CallBack methods. 

boolean mqttConnect() {
  SerialMon.print(F("Connecting to "));
  SerialMon.print(broker);

  // Connect to MQTT Broker
#ifdef PUBSUB
  boolean status = mqtt.connect("id","gate/lastWill",0,false,"die");  
#else
  mqtt.setWill("gate/lastWill", "die");
  boolean status = mqtt.connect("id");  
#endif

  if (status == false) {
    SerialMon.println(F(" fail"));
    return false;
  }
  SerialMon.println(F(" success"));
  #ifdef PUBSUB
    mqtt.publish(topicInit, "started");
    mqtt.subscribe(topicLed); 
  #else
    mqtt.publish(topicInit, "started");
    mqtt.subscribe(topicLed); 
  #endif    
  return mqtt.connected();
}

#ifdef PUBSUB
void mqttCallback(char* topic, byte* payload, unsigned int len) {
  SerialMon.print(F("Message arrived ["));
  SerialMon.print(topic);
  SerialMon.print(F("]: "));
  SerialMon.write(payload, len);
  SerialMon.println();

  // Only proceed if incoming message's topic matches
  if (String(topic) == topicLed) {
#else
void mqttCallback(String &topic, String &payload) {
  SerialMon.print(F("Message arrived ["));
  SerialMon.print(topic);
  SerialMon.print(F("]: "));
  SerialMon.println(payload);

  // Only proceed if incoming message's topic matches
  if (topic == topicLed) {  
#endif

    ledStatus = !ledStatus;
    digitalWrite(LED_PIN, ledStatus);
    #ifdef PUBSUB
      mqtt.publish(topicLedStatus, ledStatus ? "1" : "0");
    #else
      //200203: It is better NOT to publish anything inside a Callback method
      //mqtt.publish(topicLedStatus, ledStatus ? "1" : "0");
      //mqtt.publish(topicLedStatus, ledStatus ? "1" : "0", false, 2);
      msg4ledStatus = true;
    #endif    
  }
}

void setup() {

  // Set console baud rate
  SerialMon.begin(115200);
  delay(10);

  // Set your reset, enable, power pins here
  pinMode(LED_PIN, OUTPUT);

  // !!!!!!!!!!!
  // Set your reset, enable, power pins here
  // !!!!!!!!!!!
  pinMode(9, OUTPUT);
  digitalWrite(9, HIGH);  //turn on Mosfet

  SerialMon.println(F("Wait..."));

  // Set GSM module baud rate
  //TinyGsmAutoBaud(SerialAT,GSM_AUTOBAUD_MIN,GSM_AUTOBAUD_MAX);
  SerialAT.begin(2400);
  delay(3000);

  // Restart takes quite some time
  // To skip it, call init() instead of restart()
  SerialMon.println(F("Initializing modem..."));
  modem.restart();
  // modem.init();

  String modemInfo = modem.getModemInfo();
  SerialMon.print(F("Modem info: "));
  SerialMon.println(modemInfo);

#if TINY_GSM_USE_GPRS
  // Unlock your SIM card with a PIN if needed
  if ( GSM_PIN && modem.getSimStatus() != 3 ) {
    modem.simUnlock(GSM_PIN);
  }
#endif

  SerialMon.print(F("Waiting for network..."));
  if (!modem.waitForNetwork()) {
    SerialMon.println(F(" fail"));
    delay(10000);
    return;
  }
  SerialMon.println(F(" success"));

  if (modem.isNetworkConnected()) {
    SerialMon.println(F("Network connected"));
  }

#if TINY_GSM_USE_GPRS
  // GPRS connection parameters are usually set after network registration
    SerialMon.print(F("Connecting to "));
    SerialMon.print(apn);
    if (!modem.gprsConnect(apn, gprsUser, gprsPass)) {
      SerialMon.println(F(" fail"));
      delay(10000);
      return;
    }
    SerialMon.println(F(" success"));

    if (modem.isGprsConnected()) {
      SerialMon.println(F("GPRS connected"));
    }
#endif

  #ifdef PUBSUB
    // MQTT Broker setup
    mqtt.setServer(broker, port);
    mqtt.setCallback(mqttCallback);
  #else
    // MQTT Broker setup
    mqtt.setOptions(10, true, 15000);  //With timeout = 1000, it can't connect.
    mqtt.begin(broker, port, client);
    mqtt.onMessage(mqttCallback); 
  #endif    

}

void loop() {

  if (!mqtt.connected()) {
#ifdef PUBSUB
    SerialMon.println(F("=== MQTT NOT CONNECTED ===  "));
#else
    SerialMon.print(F("=== MQTT NOT CONNECTED ===  "));
    SerialMon.print(F("lastError - returnCode: "));
    SerialMon.print(mqtt.lastError());
    SerialMon.print(F(" - "));
    SerialMon.println(mqtt.returnCode());
#endif    
    // Reconnect every 10 seconds
    unsigned long t = millis();
    if (t - lastReconnectAttempt > 10000L) {
      lastReconnectAttempt = t;
      if (mqttConnect()) {
        lastReconnectAttempt = 0;
      }
    }
    delay(100);
    return;
  }
  mqtt.loop();
  if (msg4ledStatus) {
      mqtt.publish(topicLedStatus, ledStatus ? "1" : "0");
      msg4ledStatus = false;
  }

  if ( (unsigned long)(millis() - lastVcc) > loopVcc) {
      //Debo enviar el Vcc
      unsigned int vcc = modem.getBattVoltage();
      char cadena[16];
      sprintf(cadena, "%d", vcc);
      SerialMon.print(F("Vcc: "));
      SerialMon.println(cadena);
      mqtt.publish(topicVcc, cadena);
      lastVcc = millis();
  }
}

NOTE: I have add a serial.println in TinyGSM library to see the buffer. You can see it in "vertical" lines. First line is "BUFFER:". Long ones is timestamp sent from node red. But buffer is only 27 chars at most.

And now I will publish 3 logs (both serial log and node red log):

  1. pubsubclient: In this case I left the arduino to do its job. Send Vcc every minute. As you can see I get more than 4 msg with Vcc data. So everything is Ok

  2. pubsubclient: In this case, I also send msg (timestamp) from Node red to arduino to switch on/off the led. Meanwhile, arduino is sending Vcc data. Everything is Ok.

  3. arduino-mqtt library: here we have a big log to test everything. It is a very long log but I will split it in three parts 3.1 first part is to see how MQTT disconnect after the second Vcc message. 3.2 second part is to see what happens when we send from Node Red a message to switch on/off the led. If we stop sending msg from node red, after the second Vcc data in a row, MQTT IS DISCONNECTED again. (see part 3.3) 3.3 I f we send a node red msg every time I get Vcc data, MQTT DON'T disconnect. But if we dont send anything from Nodered, after two Vcc msg in a row --> MQTT DISCONNECTs.

I am getting crazy. it is a very strange behaviour. May be I have done something wrong in my sketch? Where or how could I go on debuging?

Thanks

NOTE: In order not to waste a lot of time reading logs, you can find in the begging of each part the "timings" in where are interested things as Vcc data, nodered msg recieved, MQTT disconnects .... (I wil write seeconds, remember that logs are in "[millis()]")

  1. pubsubclient:

See these seconds: 59: Vcc 122: Vcc 185: Vcc

Wait...
Initializing modem...
[3530] ### Unhandled: ÿ
[7870] ### TinyGSM Version: 0.9.17
[8083] ### Unhandled: ÿ
[8462] ### Modem: ¤EH¨Ð¥(UJ[02]Šj

SIMCOM SIM800L
[8464] ### Modem: ¤EH¨Ð¥(UJ[02]Šj

SIMCOM SIM800L
Modem info: SIM800 R14.18
Waiting for network... success
Network connected
Connecting to orangeworld success
GPRS connected
[19308] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  
Connecting to XXXXXXX.com[21489] ### Available: 0 on 1
[21997] ### Available: 0 on 1
[22497] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[22632] ### READ: 4 from 1
 success
[23144] ### Available: 0 on 1
[23429] ### Got Data: 1
[23664] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[02]
[00]
[23799] ### READ: 5 from 1
[24164] ### Available: 0 on 1
...
[38268] ### Available: 0 on 1
[38584] ### Got Data: 1
[38709] ### Available: 2 on 1
[38828] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[38944] ### READ: 2 from 1
[39335] ### Available: 0 on 1
...
[53385] ### Available: 0 on 1
[53770] ### Got Data: 1
[53895] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[54022] ### READ: 2 from 1
[54394] ### Available: 0 on 1
...
[59916] ### Available: 0 on 1
Vcc: 3856
[62367] ### Available: 0 on 1
...
[69412] ### Available: 0 on 1
[69933] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[70060] ### READ: 2 from 1
[70416] ### Available: 0 on 1
...
[84465] ### Available: 0 on 1
[84828] ### Got Data: 1
[84957] ### Available: 2 on 1
[85080] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[85200] ### READ: 2 from 1
[85585] ### Available: 0 on 1
...
[99641] ### Available: 0 on 1
[99999] ### Got Data: 1
[100126] ### Available: 2 on 1
[100249] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[100374] ### READ: 2 from 1
[100755] ### Available: 0 on 1
...
[114800] ### Available: 0 on 1
[115146] ### Got Data: 1
[115263] ### Available: 2 on 1
[115384] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[115511] ### READ: 2 from 1
[115890] ### Available: 0 on 1
...
[122411] ### Available: 0 on 1
Vcc: 3856
[124979] ### Available: 0 on 1
...
[130529] ### Available: 0 on 1
[130867] ### Got Data: 1
[130992] ### Available: 2 on 1
[131115] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[131229] ### READ: 2 from 1
[131618] ### Available: 0 on 1
...
[145672] ### Available: 0 on 1
[146003] ### Got Data: 1
[146122] ### Available: 2 on 1
[146245] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[146372] ### READ: 2 from 1
[146747] ### Available: 0 on 1
...
[160798] ### Available: 0 on 1
[161134] ### Got Data: 1
[161255] ### Available: 2 on 1
[161380] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[161507] ### READ: 2 from 1
[161882] ### Available: 0 on 1
...
[175927] ### Available: 0 on 1
[176269] ### Got Data: 1
[176394] ### Available: 2 on 1
[176515] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[176642] ### READ: 2 from 1
[177022] ### Available: 0 on 1
...
[185051] ### Available: 0 on 1
Vcc: 3856
[187598] ### Available: 0 on 1
...
[192141] ### Available: 0 on 1
[192563] ### Got Data: 1
[192690] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[192819] ### READ: 2 from 1
[193187] ### Available: 0 on 1
[193691] ### Available: 0 on 1
5/2/2020 20:52:03node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:53:00node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3856", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:54:29node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3856", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:55:59node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3856", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:56:28node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
  1. pubsubclient + sending timestamp from node red

See these seconds. 59: Vcc 69: switch on/off led 86: switch on/off led 92: switch on/off led 120: switch on/off led 122: Vcc

Wait...
tializing modem...
[3530] ### Unhandled: ÿ
ÿ7878] ### TinyGSM Version: 0.9.17
[8091] ### Unhandled: ÿ
[8493] ### Modem: *VC¡Hhi[19]U9é 1

SIMCOM SIM800L
[8495] ### Modem: *VC¡Hhi[19]U9é 1

SIMCOM SIM800L
Modem info: SIM800 R14.18
Waiting for network... success
Network connected
Connecting to orangeworld success
GPRS connected
[19949] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  
Connecting to XXXXXXXX.com[21692] ### Available: 0 on 1
[21964] ### Got Data: 1
[22095] ### Available: 4 on 1
[22218] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[22339] ### READ: 4 from 1
 success
[22851] ### Available: 0 on 1
[23134] ### Got Data: 1
[23369] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[02]
[00]
[23502] ### READ: 5 from 1
[23869] ### Available: 0 on 1
...
[37974] ### Available: 0 on 1
[38502] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[38629] ### READ: 2 from 1
[38985] ### Available: 0 on 1
...
[53043] ### Available: 0 on 1
[53366] ### Got Data: 1
[53487] ### Available: 2 on 1
[53616] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[53733] ### READ: 2 from 1
[54112] ### Available: 0 on 1
...
[59629] ### Available: 0 on 1
Vcc: 3873
[62224] ### Available: 0 on 1
...
[69294] ### Available: 0 on 1
[69791] ### Available: 27 on 1
BUFFER: 
Ð
[00]
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
0
7
2
2
5
0
7
[69976] ### READ: 27 from 1
Message arrived [gate/led]: 1580930722507
[70301] ### Available: 0 on 1
...
[85360] ### Available: 0 on 1
[85735] ### Got Data: 1
[85854] ### Available: 2 on 1
[85979] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[86108] ### READ: 2 from 1
[86185] ### Got Data: 1
[86312] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
0
7
4
6
7
3
6
[86501] ### READ: 25 from 1
Message arrived [gate/led]: 1580930746736
[86642] ### Available: 0 on 1
...
[91699] ### Available: 0 on 1
[91985] ### Got Data: 1
[92121] ### Available: 25 on 1
[92241] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
0
7
5
5
0
3
4
[92424] ### READ: 25 from 1
Message arrived [gate/led]: 1580930755034
[92755] ### Available: 0 on 1
...
[107311] ### Available: 0 on 1
[107681] ### Got Data: 1
[107802] ### Available: 2 on 1
[107927] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[108056] ### READ: 2 from 1
[108429] ### Available: 0 on 1
...
[119463] ### Available: 0 on 1
[119740] ### Got Data: 1
[119877] ### Available: 25 on 1
[120012] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
0
7
9
4
9
5
7
[120188] ### READ: 25 from 1
Message arrived [gate/led]: 1580930794957
[120526] ### Available: 0 on 1
...
[122529] ### Available: 0 on 1
Vcc: 3840
[124981] ### Available: 0 on 1
...
5/2/2020 20:24:16node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:25:13node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3873", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:25:23node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580930722507", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:25:24node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:25:47node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580930746736", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:25:49node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "0", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:25:55node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580930755034", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:25:57node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:26:35node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580930794957", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:26:38node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "0", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:26:44node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3840", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:27:07node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
  1. arduino-mqtt. 3.1 first part is to see how MQTT disconnect after the second Vcc message. You can see every 60 seconds Vcc, and after the second message ---> MQTT disconnets. In node red we can see several INIT and LAST WILL.

See these seconds: 59: Vcc 122: Vcc 125: MQTT DISCONNECT 185: Vcc 248: Vcc 251: MQTT DISCONNECT

Wait...
Initializing modem...
[3530] ### Unhandled: ÿ
[7845] ### TinyGSM Version: 0.9.17
[8056] ### Unhandled: ÿ
[8443] ### Modem: T!¡B¡T•J[02]Šj

SIMCOM SIM800L
[8445] ### Modem: T!¡B¡T•J[02]Šj

SIMCOM SIM800L
Modem info: SIM800 R14.18
Waiting for network... success
Network connected
Connecting to orangeworld success
GPRS connected
[19073] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  lastError - returnCode: 0 - 0
Connecting to XXXXXX.com[21172] ### Available: 0 on 1
[21452] ### Got Data: 1
[21583] ### Available: 4 on 1
[21714] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[21848] ### READ: 4 from 1
 success
[22368] ### Available: 0 on 1
[22646] ### Got Data: 1
[22779] ### Available: 5 on 1
[22904] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[02]
[00]
[23040] ### READ: 5 from 1
[23404] ### Available: 0 on 1
...
[32491] ### Available: 0 on 1
[32882] ### Got Data: 1
[33007] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[33132] ### READ: 2 from 1
[33509] ### Available: 0 on 1
...
[42618] ### Available: 0 on 1
[43032] ### Got Data: 1
[43149] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[43274] ### READ: 2 from 1
[43657] ### Available: 0 on 1
...
[52756] ### Available: 0 on 1
[53164] ### Got Data: 1
[53291] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[53409] ### READ: 2 from 1
[53790] ### Available: 0 on 1
...
[59809] ### Available: 0 on 1
Vcc: 3867
[62255] ### Available: 0 on 1
...
[72927] ### Available: 0 on 1
[73289] ### Got Data: 1
[73406] ### Available: 2 on 1
[73533] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[73660] ### READ: 2 from 1
[74035] ### Available: 0 on 1
...
[83064] ### Available: 0 on 1
[83427] ### Got Data: 1
[83548] ### Available: 2 on 1
[83677] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[83808] ### READ: 2 from 1
[84174] ### Available: 0 on 1
...
[93202] ### Available: 0 on 1
[93519] ### Got Data: 1
[93642] ### Available: 2 on 1
[93765] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[93896] ### READ: 2 from 1
[94267] ### Available: 0 on 1
...
[103350] ### Available: 0 on 1
[103688] ### Got Data: 1
[103806] ### Available: 2 on 1
[103933] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[104048] ### READ: 2 from 1
[104435] ### Available: 0 on 1
...
[113477] ### Available: 0 on 1
[113852] ### Got Data: 1
[113975] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[114094] ### READ: 2 from 1
[114479] ### Available: 0 on 1
...
[122509] ### Available: 0 on 1
Vcc: 3867
[124958] ### Available: 0 on 1
[125507] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  lastError - returnCode: -6 - 0
Connecting to XXXXXX.com[127039] ### Available: 0 on 1
[127320] ### Got Data: 1
[127453] ### Available: 4 on 1
[127580] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[127713] ### READ: 4 from 1
 success
[128229] ### Available: 0 on 1
[128739] ### Available: 0 on 1
[129228] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[03]
[00]
[129372] ### READ: 5 from 1
[129728] ### Available: 0 on 1
...
[138866] ### Available: 0 on 1
[138981] ### Got Data: 1
[139266] ### Available: 2 on 1
[139393] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[139520] ### READ: 2 from 1
[139892] ### Available: 0 on 1
...
[148492] ### Available: 0 on 1
[148840] ### Got Data: 1
[148957] ### Available: 2 on 1
[149086] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[149213] ### READ: 2 from 1
[149585] ### Available: 0 on 1
...
[158625] ### Available: 0 on 1
[158932] ### Got Data: 1
[159051] ### Available: 2 on 1
[159178] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[159301] ### READ: 2 from 1
[159672] ### Available: 0 on 1
...
[168769] ### Available: 0 on 1
[169068] ### Got Data: 1
[169189] ### Available: 2 on 1
[169316] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[169441] ### READ: 2 from 1
[169818] ### Available: 0 on 1
...
[178909] ### Available: 0 on 1
[179304] ### Got Data: 1
[179433] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[179560] ### READ: 2 from 1
[179935] ### Available: 0 on 1
...
[185448] ### Available: 0 on 1
Vcc: 3862
[187901] ### Available: 0 on 1
...
[198563] ### Available: 0 on 1
[198957] ### Got Data: 1
[199075] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[199204] ### READ: 2 from 1
[199585] ### Available: 0 on 1
...
[208703] ### Available: 0 on 1
[209059] ### Got Data: 1
[209178] ### Available: 2 on 1
[209307] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[209420] ### READ: 2 from 1
[209803] ### Available: 0 on 1
...
[218839] ### Available: 0 on 1
[219160] ### Got Data: 1
[219285] ### Available: 2 on 1
[219408] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[219537] ### READ: 2 from 1
[219910] ### Available: 0 on 1
...
[228972] ### Available: 0 on 1
[229324] ### Got Data: 1
[229451] ### Available: 2 on 1
[229576] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[229695] ### READ: 2 from 1
[230076] ### Available: 0 on 1
...
[239108] ### Available: 0 on 1
[239448] ### Got Data: 1
[239575] ### Available: 2 on 1
[239699] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[239822] ### READ: 2 from 1
[240203] ### Available: 0 on 1
...
[248227] ### Available: 0 on 1
Vcc: 3867
[250675] ### Available: 0 on 1
[251228] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  lastError - returnCode: -6 - 0
Connecting to XXXXXX.com[253059] ### Available: 0 on 1
[253341] ### Got Data: 1
[253472] ### Available: 4 on 1
[253599] ### Available: 4 on 1
5/2/2020 20:29:11node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:30:10node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3867", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:31:39node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
5/2/2020 20:31:44node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:33:11node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3862", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:34:40node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
5/2/2020 20:34:46node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }

3.2 second part is to see what happens when we send from Node Red a message to switch on/off the led. If we stop sending msg from node red, after the second Vcc data in a row, MQTT IS DISCONNECTED again. (see part 3.3)

See these seconds: 59: Vcc 122: Vcc 125: MQTT DISCONNECT 185: Vcc 248: Vcc 251: MQTT DISCONNECT ----- end of part 3.1 and start of part 3.2 ------ 259: switch on/off led 265: switch on/off led 311: Vcc 373: Vcc 377: MQTT DISCONNECT 437: Vcc 445: switch on/off led 456: switch on/off led 468: switch on/off led 474: switch on/off led 500: Vcc 562: Vcc 566: MQTT DISCONNECT

=== MQTT NOT CONNECTED ===  lastError - returnCode: -6 - 0
Connecting to XXXXXX.com[253059] ### Available: 0 on 1
[253341] ### Got Data: 1
[253472] ### Available: 4 on 1
[253599] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[253720] ### READ: 4 from 1
 success
[254224] ### Available: 0 on 1
[254730] ### Available: 0 on 1
[255221] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[04]
[00]
[255358] ### READ: 5 from 1
[255725] ### Available: 0 on 1
...
[258734] ### Available: 0 on 1
[259147] ### Got Data: 1
[259278] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
2
9
1
7
3
6
[259469] ### READ: 25 from 1
Message arrived [gate/led]: 1580931291736
[259782] ### Available: 0 on 1
...
[264810] ### Available: 0 on 1
[265328] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
3
0
0
4
9
5
[265512] ### READ: 25 from 1
Message arrived [gate/led]: 1580931300495
[265836] ### Available: 0 on 1
...
[275976] ### Available: 0 on 1
[276375] ### Got Data: 1
[276502] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[276631] ### READ: 2 from 1
[277006] ### Available: 0 on 1
...
[286111] ### Available: 0 on 1
[286490] ### Got Data: 1
[286607] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[286722] ### READ: 2 from 1
[287119] ### Available: 0 on 1
...
[296257] ### Available: 0 on 1
[296617] ### Got Data: 1
[296744] ### Available: 2 on 1
[296873] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[297005] ### READ: 2 from 1
[297371] ### Available: 0 on 1
...
[306405] ### Available: 0 on 1
[306769] ### Got Data: 1
[306898] ### Available: 2 on 1
[307023] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[307144] ### READ: 2 from 1
[307523] ### Available: 0 on 1
...
[311033] ### Available: 0 on 1
Vcc: 3856
[313479] ### Available: 0 on 1
...
[324145] ### Available: 0 on 1
[324519] ### Got Data: 1
[324636] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[324761] ### READ: 2 from 1
[325148] ### Available: 0 on 1
...
[334274] ### Available: 0 on 1
[334635] ### Got Data: 1
[334751] ### Available: 2 on 1
[334878] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[334993] ### READ: 2 from 1
[335380] ### Available: 0 on 1
...
[344412] ### Available: 0 on 1
[344711] ### Got Data: 1
[344838] ### Available: 2 on 1
[344963] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[345088] ### READ: 2 from 1
[345460] ### Available: 0 on 1
...
[354549] ### Available: 0 on 1
[354867] ### Got Data: 1
[354988] ### Available: 2 on 1
[355115] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[355244] ### READ: 2 from 1
[355612] ### Available: 0 on 1
...
[364683] ### Available: 0 on 1
[365090] ### Got Data: 1
[365219] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[365344] ### READ: 2 from 1
[365715] ### Available: 0 on 1
...
[373745] ### Available: 0 on 1
Vcc: 3862
[376197] ### Available: 0 on 1
[377552] ### Unhandled: 1, SEND FAIL
[377772] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  lastError - returnCode: -6 - 0
Connecting to XXXXXX.com[379490] ### Available: 0 on 1
[379766] ### Got Data: 1
[379899] ### Available: 4 on 1
[380028] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[380157] ### READ: 4 from 1
 success
[380653] ### Available: 0 on 1
[380946] ### Got Data: 1
[381081] ### Available: 5 on 1
[381208] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[05]
[00]
[381341] ### READ: 5 from 1
[381710] ### Available: 0 on 1
...
[390787] ### Available: 0 on 1
[391141] ### Got Data: 1
[391268] ### Available: 2 on 1
[391389] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[391518] ### READ: 2 from 1
[391895] ### Available: 0 on 1
...
[400930] ### Available: 0 on 1
[401457] ### Available: 1 on 1
BUFFER: 
Ð
[401573] ### READ: 1 from 1
BUFFER: 
[00]
[401711] ### READ: 1 from 1
[401930] ### Available: 0 on 1
...
[411060] ### Available: 0 on 1
[411410] ### Got Data: 1
[411527] ### Available: 2 on 1
[411654] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[411781] ### READ: 2 from 1
[412153] ### Available: 0 on 1
...
[421189] ### Available: 0 on 1
[421556] ### Got Data: 1
[421677] ### Available: 2 on 1
[421799] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[421926] ### READ: 2 from 1
[422297] ### Available: 0 on 1
...
[431337] ### Available: 0 on 1
[431675] ### Got Data: 1
[431792] ### Available: 2 on 1
[431919] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[432046] ### READ: 2 from 1
[432418] ### Available: 0 on 1
...
[437436] ### Available: 0 on 1
Vcc: 3851
[439889] ### Available: 0 on 1
...
[444944] ### Available: 0 on 1
[445220] ### Got Data: 1
[445356] ### Available: 25 on 1
[445483] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
5
5
9
5
6
8
[445673] ### READ: 25 from 1
Message arrived [gate/led]: 1580931559568
[445988] ### Available: 0 on 1
...
[456124] ### Available: 0 on 1
[456402] ### Got Data: 1
[456540] ### Available: 25 on 1
[456671] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
5
7
6
0
7
1
[456849] ### READ: 25 from 1
[456912] ### Got Data: 1
[457039] ### Available: 2 on 1
Message arrived [gate/led]: 1580931576071
[457345] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[457474] ### READ: 2 from 1
[457848] ### Available: 0 on 1
...
[467486] ### Available: 0 on 1
[467761] ### Got Data: 1
[467898] ### Available: 25 on 1
[468025] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]

g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
5
9
2
3
4
8
[468207] ### READ: 25 from 1
Message arrived [gate/led]: 1580931592348
[468531] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[468649] ### READ: 2 from 1
[469028] ### Available: 0 on 1
...
[473548] ### Available: 0 on 1
[473829] ### Got Data: 1
[473966] ### Available: 25 on 1
[474093] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
6
0
1
2
9
7
[474275] ### READ: 25 from 1
Message arrived [gate/led]: 1580931601297
[474603] ### Available: 0 on 1
...
[484747] ### Available: 0 on 1
[485124] ### Got Data: 1
[485244] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[485373] ### READ: 2 from 1
[485750] ### Available: 0 on 1
...
[494876] ### Available: 0 on 1
[495220] ### Got Data: 1
[495339] ### Available: 2 on 1
[495464] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[495581] ### READ: 2 from 1
[495966] ### Available: 0 on 1
...
[499980] ### Available: 0 on 1
Vcc: 3862
[502528] ### Available: 0 on 1
...
[513185] ### Available: 0 on 1
[513566] ### Got Data: 1
[513685] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[513812] ### READ: 2 from 1
[514195] ### Available: 0 on 1
...
[523331] ### Available: 0 on 1
[523700] ### Got Data: 1
[523827] ### Available: 2 on 1
[523952] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[524077] ### READ: 2 from 1
[524455] ### Available: 0 on 1
...
[533483] ### Available: 0 on 1
[533862] ### Got Data: 1
[533987] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[534106] ### READ: 2 from 1
[534480] ### Available: 0 on 1
...
[543619] ### Available: 0 on 1
[543989] ### Got Data: 1
[544118] ### Available: 2 on 1
[544237] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[544362] ### READ: 2 from 1
[544745] ### Available: 0 on 1
...
[553779] ### Available: 0 on 1
[554121] ### Got Data: 1
[554237] ### Available: 2 on 1
[554366] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[554500] ### READ: 2 from 1
[554862] ### Available: 0 on 1
...
[562892] ### Available: 0 on 1
Vcc: 3862
[565352] ### Available: 0 on 1
[565884] ### Available: 0 on 1
[566394] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  lastError - returnCode: 0 - 0
Connecting to XXXXXX.com[568559] ### Available: 0 on 1
[568836] ### Got Data: 1
[568969] ### Available: 4 on 1
[569096] ### Available: 4 on 1
5/2/2020 20:34:52node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931291736", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:34:54node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:35:01node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931300495", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:35:03node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "0", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:36:12node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3856", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:37:41node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
5/2/2020 20:37:47node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:39:14node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3851", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:39:20node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931559568", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:39:22node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:39:36node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931576071", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:39:38node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "0", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:39:53node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931592348", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:39:55node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:40:02node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931601297", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:40:04node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "0", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:40:45node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3862", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:42:14node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }

3.3 I f we send a node red msg every time I get Vcc data, MQTT DON'T disconnect. But if we dont send anything from Nodered, after two Vcc msg in a row --> MQTT DISCONNECTs.

It is VERY VERY STRANGE, isn't it ? ;)

See these seconds: 59: Vcc 122: Vcc 125: MQTT DISCONNECT 185: Vcc 248: Vcc 251: MQTT DISCONNECT ----- end of part 3.1 and start of part 3.2 ------ 259: switch on/off led 265: switch on/off led 311: Vcc 373: Vcc 377: MQTT DISCONNECT 437: Vcc 445: switch on/off led 456: switch on/off led 468: switch on/off led 474: switch on/off led 500: Vcc 562: Vcc 566: MQTT DISCONNECT ----- end of part 3.2 and start of part 3.3 ------ 625: Vcc 634: switch on/off led 688: Vcc 696: switch on/off led 751: Vcc 757: switch on/off led 814: Vcc 867: Vcc 879: MQTT DISCONNECT

=== MQTT NOT CONNECTED ===  lastError - returnCode: 0 - 0
Connecting to XXXXXX.com[568559] ### Available: 0 on 1
[568836] ### Got Data: 1
[568969] ### Available: 4 on 1
[569096] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[569229] ### READ: 4 from 1
 success
[569751] ### Available: 0 on 1
[570036] ### Got Data: 1
[570169] ### Available: 5 on 1
[570292] ### Available: 5 on 1
BUFFER: 

[03]
[00]
[06]
[00]
[570415] ### READ: 5 from 1
[570798] ### Available: 0 on 1
...
[579874] ### Available: 0 on 1
[580245] ### Got Data: 1
[580370] ### Available: 2 on 1
[580495] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[580626] ### READ: 2 from 1
[580995] ### Available: 0 on 1
...
[590026] ### Available: 0 on 1
[590376] ### Got Data: 1
[590497] ### Available: 2 on 1
[590618] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[590745] ### READ: 2 from 1
[591116] ### Available: 0 on 1
...
[600162] ### Available: 0 on 1
[600676] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[600805] ### READ: 2 from 1
[601165] ### Available: 0 on 1
...
[610304] ### Available: 0 on 1
[610643] ### Got Data: 1
[610772] ### Available: 2 on 1
[610891] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[611012] ### READ: 2 from 1
[611403] ### Available: 0 on 1
...
[620445] ### Available: 0 on 1
[620761] ### Got Data: 1
[620888] ### Available: 2 on 1
[621006] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[621133] ### READ: 2 from 1
[621516] ### Available: 0 on 1
...
[625528] ### Available: 0 on 1
Vcc: 3856
[627996] ### Available: 0 on 1
...
[633563] ### Available: 0 on 1
[633841] ### Got Data: 1
[633980] ### Available: 25 on 1
[634109] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
8
3
1
1
5
5
[634292] ### READ: 25 from 1
Message arrived [gate/led]: 1580931831155
[634613] ### Available: 0 on 1
...
[644763] ### Available: 0 on 1
[645271] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[645394] ### READ: 2 from 1
[645763] ### Available: 0 on 1
...
[654956] ### Available: 0 on 1
[655349] ### Got Data: 1
[655472] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[655601] ### READ: 2 from 1
[655974] ### Available: 0 on 1
...
[665088] ### Available: 0 on 1
[665427] ### Got Data: 1
[665554] ### Available: 2 on 1
[665683] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[665810] ### READ: 2 from 1
[666185] ### Available: 0 on 1
...
[675221] ### Available: 0 on 1
[675567] ### Got Data: 1
[675694] ### Available: 2 on 1
[675813] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[675930] ### READ: 2 from 1
[676321] ### Available: 0 on 1
...
[685352] ### Available: 0 on 1
[685717] ### Got Data: 1
[685844] ### Available: 2 on 1
[685969] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[686098] ### READ: 2 from 1
[686473] ### Available: 0 on 1
...
[688476] ### Available: 0 on 1
Vcc: 3846
[690929] ### Available: 0 on 1
...
[695990] ### Available: 0 on 1
[696272] ### Got Data: 1
[696408] ### Available: 25 on 1
[696532] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
1
9
2
0
9
1
7
[696715] ### READ: 25 from 1
Message arrived [gate/led]: 1580931920917
[697057] ### Available: 0 on 1
...
[707186] ### Available: 0 on 1
[707571] ### Got Data: 1
[707696] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[707813] ### READ: 2 from 1
[708198] ### Available: 0 on 1
...
[717318] ### Available: 0 on 1
[717664] ### Got Data: 1
[717791] ### Available: 2 on 1
[717910] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[718028] ### READ: 2 from 1
[718417] ### Available: 0 on 1
...
[727457] ### Available: 0 on 1
[727969] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[728098] ### READ: 2 from 1
[728463] ### Available: 0 on 1
...
[737589] ### Available: 0 on 1
[737925] ### Got Data: 1
[738041] ### Available: 2 on 1
[738166] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[738281] ### READ: 2 from 1
[738670] ### Available: 0 on 1
...
[747712] ### Available: 0 on 1
[748032] ### Got Data: 1
[748158] ### Available: 2 on 1
[748283] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[748410] ### READ: 2 from 1
[748787] ### Available: 0 on 1
...
[751292] ### Available: 0 on 1
Vcc: 3846
[753752] ### Available: 0 on 1
...
[757299] ### Available: 0 on 1
[757579] ### Got Data: 1
[757714] ### Available: 25 on 1
[757841] ### Available: 25 on 1
BUFFER: 
0
[17]
[00]
[08]
g
a
t
e
/
l
e
d
1
5
8
0
9
3
2
0
0
9
8
4
0
[758022] ### READ: 25 from 1
Message arrived [gate/led]: 1580932009840
[758360] ### Available: 0 on 1
...
[768495] ### Available: 0 on 1
[768888] ### Got Data: 1
[769015] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[769134] ### READ: 2 from 1
[769513] ### Available: 0 on 1
...
[778622] ### Available: 0 on 1
[778975] ### Got Data: 1
[779104] ### Available: 2 on 1
[779225] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[779350] ### READ: 2 from 1
[779730] ### Available: 0 on 1
...
[788764] ### Available: 0 on 1
[789096] ### Got Data: 1
[789215] ### Available: 2 on 1
[789342] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[789469] ### READ: 2 from 1
[789846] ### Available: 0 on 1
...
[798887] ### Available: 0 on 1
[799225] ### Got Data: 1
[799342] ### Available: 2 on 1
[799469] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[799596] ### READ: 2 from 1
[799969] ### Available: 0 on 1
...
[809017] ### Available: 0 on 1
[809383] ### Got Data: 1
[809502] ### Available: 2 on 1
[809631] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[809760] ### READ: 2 from 1
[810131] ### Available: 0 on 1
...
[814141] ### Available: 0 on 1
Vcc: 3851
[816594] ### Available: 0 on 1
...
[827271] ### Available: 0 on 1
[827650] ### Got Data: 1
[827781] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[827910] ### READ: 2 from 1
[828278] ### Available: 0 on 1
...
[837394] ### Available: 0 on 1
[837773] ### Got Data: 1
[837892] ### Available: 2 on 1
[838021] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[838144] ### READ: 2 from 1
[838520] ### Available: 0 on 1
...
[847544] ### Available: 0 on 1
[847931] ### Got Data: 1
[848052] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[848168] ### READ: 2 from 1
[848560] ### Available: 0 on 1
...
[857671] ### Available: 0 on 1
[858052] ### Got Data: 1
[858177] ### Available: 2 on 1
[858304] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[858433] ### READ: 2 from 1
[858806] ### Available: 0 on 1
...
[867833] ### Available: 0 on 1
[868157] ### Got Data: 1
[868282] ### Available: 2 on 1
[868401] ### Available: 2 on 1
BUFFER: 
Ð
[00]
[868526] ### READ: 2 from 1
[868911] ### Available: 0 on 1
...
[876937] ### Available: 0 on 1
Vcc: 3856
[879384] ### Available: 0 on 1
[879933] ### Available: 0 on 1
=== MQTT NOT CONNECTED ===  lastError - returnCode: -6 - 0
Connecting to XXXXXX.com[881776] ### Available: 0 on 1
[882055] ### Got Data: 1
[882192] ### Available: 4 on 1
[882315] ### Available: 4 on 1
BUFFER: 

[02]
[00]
[00]
[882444] ### READ: 4 from 1
 success
[882946] ### Available: 0 on 1
[883476] ### Available: 1 on 1
BUFFER: 

[883603] ### READ: 1 from 1
BUFFER: 
[03]
[00]
[07]
[00]
[883744] ### READ: 4 from 1
[883984] ### Available: 0 on 1
[884490] ### Available: 0 on 1
[884989] ### Available: 0 on 1
[885487] ### Available: 0 on 1
[885991] ### Available: 0 on 1
[887218] ### Unhandled: O
5/2/2020 20:42:20node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:43:45node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3856", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:43:51node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931831155", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:43:54node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:45:16node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3846", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:45:21node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580931920917", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:45:24node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "0", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:46:46node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3846", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:46:50node: 1f52d5a1.07317a
gate/led : msg : Object
{ topic: "gate/led", payload: "1580932009840", qos: 0, retain: false, _topic: "gate/led" … }
5/2/2020 20:46:52node: 1f52d5a1.07317a
gate/ledStatus : msg : Object
{ topic: "gate/ledStatus", payload: "1", qos: 0, retain: false, _topic: "gate/ledStatus" … }
5/2/2020 20:48:17node: 1f52d5a1.07317a
gate/vcc : msg : Object
{ topic: "gate/vcc", payload: "3851", qos: 0, retain: false, _topic: "gate/vcc" … }
5/2/2020 20:49:46node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
5/2/2020 20:49:51node: 1f52d5a1.07317a
gate/init : msg : Object
{ topic: "gate/init", payload: "started", qos: 0, retain: false, _topic: "gate/init" … }
5/2/2020 20:50:07node: 1f52d5a1.07317a
gate/lastWill : msg : Object
{ topic: "gate/lastWill", payload: "die", qos: 0, retain: false, _topic: "gate/lastWill" … }
256dpi commented 4 years ago

The lastError: -6 (LWMQTT_NETWORK_FAILED_WRITE) indicates that there was an issue while writing something. Since you're printing the error after client->connected() we do not know which call caused the error. Most methods return a boolean to indicate the calls success. If it failed you should check lastError immediately and print it. Then we know which call was not successful.

Teddyz commented 4 years ago

It might be obvious, but it would be great if you could add in the documentation or in an example if 1 means sent OK or if 0 means "No Error".

Is it possible to get the error-texts from the library? (Or would that consume a lot of ram?)

256dpi commented 4 years ago

In all cases true means success. I updated the docs accordingly.

I'm playing with the idea of adding a client.debug() function that prints information about whats going on under the hood. But this will consume a lot of bytes for the strings, so I'm not sure what's the best strategy here. Any ideas?

Teddyz commented 4 years ago

I saw this that might be a good approach: image

The code, in WiFiClientSecureBearSSL.cpp, seems simple (I omitted most of the cases):


// Returns an error ID and possibly a string (if dest != null) of the last
// BearSSL reported error.
int WiFiClientSecure::getLastSSLError(char *dest, size_t len) {
  int err = 0;
  const char *t = PSTR("OK");
  if (_sc || _sc_svr) {
    err = br_ssl_engine_last_error(_eng);
  }
  if (_oom_err) {
    err = -1000;
  }
  switch (err) {
    case -1000: t = PSTR("Unable to allocate memory for SSL structures and buffers."); break;
    case BR_ERR_BAD_PARAM: t = PSTR("Caller-provided parameter is incorrect."); break;
    case BR_ERR_BAD_STATE: t = PSTR("Operation requested by the caller cannot be applied with the current context state (e.g. reading data while outgoing data is waiting to be sent)."); break;
    case BR_ERR_OVERSIZED_ID: t = PSTR("ServerHello contains a session ID which is larger than 32 bytes."); break;
    case BR_ERR_BAD_CIPHER_SUITE: t = PSTR("Server wants to use a cipher suite that we did not claim to support. This is also reported if we tried to advertise a cipher suite that we do not support."); break;
    case BR_ERR_X509_DN_MISMATCH: t = PSTR("Issuer/Subject DN mismatch in the chain."); break;
    case BR_ERR_X509_WEAK_PUBLIC_KEY: t = PSTR("Public key found in certificate is too small."); break;
    case BR_ERR_X509_NOT_TRUSTED: t = PSTR("Chain could not be linked to a trust anchor."); break;
    default: t = PSTR("Unknown error code."); break;
  }
  if (dest) {
    strncpy_P(dest, t, len);
    dest[len - 1] = 0;
  }
  return err;
}`
ortegafernando commented 4 years ago

Hi, I have been doing some test.

With these options: mqtt.setOptions(10, true, 15000);

(I was used to 2400 in my old GSM SIM800 library, with TinyGSM it seems that it is better 4800)

So I will close this issue, but first: what about this?:

May be in future I will try AltSoftSerial or NeoICserial or NeoSWserial. Does anybody try them? Worth it over software serial?

Thanks.