Issues with Log.info and mqtt

While trying to mess with some mqtt issues like not being able to decode the payload. I started to use serial print for testing and it was giving me troubles so I switched to the log system. I see plenty of info from the system but nothing from the app.
Here is the code for a test argon. This is a extremely stripped code from a working system that is not using mqtt.

#include <MQTT.h>
#include <JsonParserGeneratorRK.h>

#define __FILENAME__ (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__)
char gDeviceInfo[120];  //adjust size as required

SYSTEM_THREAD(ENABLED);
SerialLogHandler LogHandler;


String cloudname = "";

int led = D7;
int count = 0;
unsigned long lastTime = 0;





MQTT client("10.0.198.254", 1883, callback, true);

void callback(char* topic, byte* payload, unsigned int length) {
  Log.info("Callback");
  client.publish("go","a");
  delay(30);
  char p[length + 1];
  memcpy(p, payload, length);
  p[length] = NULL;

  //if (!strcmp(topic,"LESS")){
    if (!strcmp(p,"ds")){
      client.publish("MORE","ds"); //not working.   not reading payload
    }
  //}

  int i = 0;
  char pay[length+1];
  for ( i; i < length; i++){
    pay[i] = ((char)payload[i]);
    Log.info("Count =%i", i);
  }
  client.publish("helpme",pay);
  Log.trace("Here: %d", pay);
}





// setup() runs once, when the device is first turned on.
void setup() {
 waitFor(Serial.isConnected, 30000);
 delay(1000);


  Particle.function("command",commandToggle);


  Particle.variable("deviceInfo",gDeviceInfo);
    snprintf(gDeviceInfo, sizeof(gDeviceInfo)
        ,"App: %s, Date: %s, Time: %s, Sysver: %s"
        ,__FILENAME__
        ,__DATE__
        ,__TIME__
        ,(const char*)System.version()  // cast required for String
    );

  pinMode(led, OUTPUT);
  digitalWrite(led, LOW);

  
  client.connect("it");
  delay(400);
  if (client.isConnected()){
    client.publish("out/here","startup");
    client.subscribe("abc123");
    client.subscribe("LESS");
  }
  
}

// loop() runs over and over again, as quickly as it can execute.
void loop() {
  // The core of your code will likely live here.
  
/*
  if (client.isConnected()){
        Serial.print("mqtt loop");
        client.loop();
        delay(3000);
  }
  else {
    client.disconnect();
    Serial.print("Reconnect");
    client.connect("it");
    client.subscribe("abc123");
    client.subscribe("LESS");
    delay(3000);
  }
  */
}
void rrhalarm () {
  JsonWriterStatic<256> jw;
  {
    JsonWriterAutoObject obj(&jw);
    jw.insertKeyValue("id", 8);
    jw.insertKeyValue("alarm", 0);
    jw.insertKeyValue("temp", 22.34);

  }
  //if (!client.isConnected()){
    //client.connect(System.deviceID());

  //}
  //if (client.isConnected()){
    //client.loop();

    client.publish("/topic_2", jw.getBuffer());
    //client.disconnect();
  //}
}
int commandToggle(String command) {
    /* Particle.functions always take a string as an argument and return an integer.
    Since we can pass a string, it means that we can give the program commands on how the function should be used.
    In this case, telling the function "on" will turn the LED on and telling it "off" will turn the LED off.
    Then, the function returns a value to us to let us know what happened.
    In this case, it will return 1 for the LEDs turning on, 0 for the LEDs turning off,
    and -1 if we received a totally bogus command that didn't do anything to the LEDs.
    */

    if (command=="restart"){
        System.reset();
        return 1;
    }
       else if (command == "mqtt"){
      int rr = rand() % (0-30+1) + 0;

      if (!client.isConnected()){
        client.connect(System.deviceID());

      }
      if (client.isConnected()){
        client.loop();

        client.publish("/topic_1", String(rr));
       // client.disconnect();
      }

      return rr;
    }
    else if (command == "mq2"){
      rrhalarm();
      return 22;
    }
    
    else {
        return -1;
    }
}

Hi, I'm not sure what is the level of Log you get with that, what if you try this instead?

SerialLogHandler logHandler(LOG_LEVEL_INFO);

Cheers

Without a parameter, SerialLogHandler defaults to LOG_LEVEL_INFO, so your Log.trace calls won't log.

But the only place I see logging messages are in callback(), and since client.loop() is commented out, I don't think the callback will ever get called.

1 Like

Callback is getting called. It is being called from the mqtt system.
In fact my one publish of go a does work.

I tried putting it to LOG_LEVEL_INFO and I'm still not getting anything from the app part.

The last entry is [system] INFO: Cloud connected

Can you add a Log.info() in loop() to verify that it works?

Does work in loop but still nothing in callback

ok, so how can we know 100% that is being called from the mqtt system?

I fell like a dummy.

I originally started adding mqtt to one semi test / production photon but when a few things didn't work I stripped the code and switched to a argon on my desk. Hence why I needed to add serial logging. When I was giving publishing mqtt messages from my computer the argon was ish not working while my photon was ansering to the top part of my call back.

Just to be sure, is the problem solved?

Well the logging problem is fixed. Now on to why I am having a hard time keeping mqtt working.

So with the reconnect code added back to the loop as well as keeping a log entry every few seconds being printed in the main loop(no delays just a counter and if statement). Loop works till I call mqtt to do something. I get my one mqtt push aswell as my first log message but then it just dies. Still keeping the breathing blue led. Since I was running a 4.x I decided to upgrade to 6.x and I am waiting on that to get done to see if that helps or not.

Ok, good to hear one problem is gone.

Now for MQTT, every time I got in trouble with it, printing extra mqtt logs helped me pinpoint the issue.

Can you enable the MQTT debug logs and see what is happening?

The file lib/MQTT-TLS/src/mbedtls/include/mbedtls/mbedtls_config.h should have this line enabled:

#define MBEDTLS_DEBUG_C

I'm not running the tls version. I'm running just the mqtt one from Hirotaka Niisato

I did find this in the header
for debugging.
// #define DEBUG_MQTT_SERIAL_OUTPUT

I turned of log handler since It looks like it uses serial.print.

Nothing is displaying except my changed loop msg.

So if I do not publish to mqtt during a call back things seem to work. Is this a known issue?

Hey, I haven't come across that issue, but it's good to know certainly.
Thanks