ESP32 OTA mqtt_client invalid header error

[Palonso]

I have installed the ESP-IDF 4.3 version and the headers error still remain, did you solve this another way?

Code: Select all

--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:6948
load:0x40078000,len:14368
load:0x40080400,len:3980
entry 0x4008067c
I (29) boot: ESP-IDF v4.3-dev-472-gcf056a7d0-dirty 2nd stage bootloader
I (29) boot: compile time 18:42:11
I (30) boot: chip revision: 1
I (34) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (41) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 16MB
I (55) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (64) boot: ## Label            Usage          Type ST Offset   Length
I (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (78) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 00100000
I (93) boot: End of partition table
I (98) boot_comm: chip revision: 1, min. application chip revision: 0
I (105) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1e750 (124752) map
I (161) esp_image: segment 1: paddr=0x0002e778 vaddr=0x3ffb0000 size=0x018a0 (  6304) load
I (164) esp_image: segment 2: paddr=0x00030020 vaddr=0x400d0020 size=0x9288c (600204) map
0x400d0020: _stext at ??:?

I (394) esp_image: segment 3: paddr=0x000c28b4 vaddr=0x3ffb18a0 size=0x021bc (  8636) load
I (398) esp_image: segment 4: paddr=0x000c4a78 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /home/pablo/esp/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1730

I (401) esp_image: segment 5: paddr=0x000c4e80 vaddr=0x40080400 size=0x15c64 ( 89188) load
I (460) boot: Loaded app from partition at offset 0x10000
I (460) boot: Disabling RNG early entropy source...
I (472) cpu_start: Pro cpu up.
I (472) cpu_start: Starting app cpu, entry point is 0x400810d8
0x400810d8: call_start_cpu1 at /home/pablo/esp/esp-idf/components/esp_system/port/cpu_start.c:109

I (0) cpu_start: App cpu up.
I (488) cpu_start: Pro cpu start user code
I (488) cpu_start: Application information:
I (488) cpu_start: Project name:     mqtt_tcp
I (493) cpu_start: App version:      1
I (498) cpu_start: Compile time:     Jul 21 2020 18:42:16
I (504) cpu_start: ELF file SHA256:  437d79a2e3d57245...
I (510) cpu_start: ESP-IDF:          v4.3-dev-472-gcf056a7d0-dirty
I (517) heap_init: Initializing. RAM available for dynamic allocation:
I (524) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (530) heap_init: At 3FFB94F0 len 00026B10 (154 KiB): DRAM
I (536) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (542) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (549) heap_init: At 40096064 len 00009F9C (39 KiB): IRAM
I (556) spi_flash: detected chip: gd
I (559) spi_flash: flash io: dio
I (564) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (574) MQTT_EXAMPLE: [APP] Startup..
I (574) MQTT_EXAMPLE: [APP] Free memory: 272276 bytes
I (584) MQTT_EXAMPLE: [APP] IDF version: v4.3-dev-472-gcf056a7d0-dirty
I (654) wifi:wifi driver task: 3ffc1b28, prio:23, stack:6656, core=0
I (654) system_api: Base MAC address is not set
I (654) system_api: read default base MAC address from EFUSE
I (674) wifi:wifi firmware version: bbe4b67
I (684) wifi:wifi certification version: v7.0
I (684) wifi:config NVS flash: enabled
I (684) wifi:config nano formating: disabled
I (684) wifi:Init data frame dynamic rx buffer num: 32
I (684) wifi:Init management frame dynamic rx buffer num: 32
I (694) wifi:Init management short buffer num: 32
I (694) wifi:Init dynamic tx buffer num: 32
I (704) wifi:Init static rx buffer size: 1600
I (704) wifi:Init static rx buffer num: 10
I (714) wifi:Init dynamic rx buffer num: 32
I (714) example_connect: Connecting to Nettra...
I (814) phy: phy_version: 4182, f1ba940, Jun  4 2020, 19:40:07, 0, 0
I (814) wifi:mode : sta (4c:11:ae:b6:d8:9c)
I (814) example_connect: Waiting for IP(s)
I (2144) wifi:new:<11,0>, old:<1,0>, ap:<255,255>, sta:<11,0>, prof:1
I (2944) wifi:state: init -> auth (b0)
I (2954) wifi:state: auth -> assoc (0)
I (2994) wifi:state: assoc -> run (10)
I (3094) wifi:connected with Nettra, aid = 3, channel 11, BW20, bssid = 68:ff:7b:4a:96:2b
I (3094) wifi:security: WPA2-PSK, phy: bgn, rssi: -19
I (3094) wifi:pm start, type: 1

I (3124) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (4644) example_connect: Got IPv6 event: Interface "example_connect: sta" address: fe80:0000:0000:0000:4e11:aeff:feb6:d89c, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5644) esp_netif_handlers: example_connect: sta ip: 192.168.86.238, mask: 255.255.255.0, gw: 192.168.86.1
I (5644) example_connect: Got IPv4 event: Interface "example_connect: sta" address: 192.168.86.238
I (5654) example_connect: Connected to example_connect: sta
I (5664) example_connect: - IPv4 address: 192.168.86.238
I (5664) example_connect: - IPv6 address: fe80:0000:0000:0000:4e11:aeff:feb6:d89c, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5684) MQTT_EXAMPLE: Other event id:7
I (6404) MQTT_EXAMPLE: MQTT_EVENT_CONNECTED
I (6404) MQTT_EXAMPLE: sent publish successful, msg_id=31011
I (6414) MQTT_EXAMPLE: sent subscribe successful, msg_id=23520
I (6414) MQTT_EXAMPLE: sent subscribe successful, msg_id=59832
I (6414) MQTT_EXAMPLE: sent unsubscribe successful, msg_id=19587
E (6604) MQTT_CLIENT: mqtt_message_receive: received a message with an invalid header=0x42
E (6604) MQTT_CLIENT: mqtt_process_receive: mqtt_message_receive() returned -1
I (6614) MQTT_EXAMPLE: MQTT_EVENT_DISCONNECTED
I (16624) MQTT_EXAMPLE: Other event id:7
I (17054) MQTT_EXAMPLE: MQTT_EVENT_CONNECTED
I (17054) MQTT_EXAMPLE: sent publish successful, msg_id=52630
I (17054) MQTT_EXAMPLE: sent subscribe successful, msg_id=38013
I (17064) MQTT_EXAMPLE: sent subscribe successful, msg_id=56284
I (17064) MQTT_EXAMPLE: sent unsubscribe successful, msg_id=2195
E (17254) MQTT_CLIENT: mqtt_message_receive: received a message with an invalid header=0x42
E (17254) MQTT_CLIENT: mqtt_process_receive: mqtt_message_receive() returned -1
I (17264) MQTT_EXAMPLE: MQTT_EVENT_DISCONNECTED
I (32264) MQTT_EXAMPLE: Other event id:7

[espnewbie]

Hello, I also got the same issue. does anyone already solved this?

Code: Select all

I (1325) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (2675) tcpip_adapter: sta ip: 192.168.254.139, mask: 255.255.255.0, gw: 192.168.254.254
I (2675) tb_ota: Connected to WI-FI, IP address: 192.168.254.139
I (2675) tb_ota: MQTT URL from flash memory: mqtt://****/
I (2685) tb_ota: MQTT port from flash memory: ****
I (2695) tb_ota: MQTT access token from flash memory: ****
I (2695) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (3675) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000
I (4705) tb_ota: Connected to MQTT broker mqtt://****/, on port ****
I (4705) tb_ota: Waiting for shared attributes response
E (5725) MQTT_CLIENT: mqtt_message_receive: received a message with an invalid header=0x42
E (5725) MQTT_CLIENT: mqtt_process_receive: mqtt_message_receive() returned -1
W (6705) tb_ota: WAIT_OTA_CONFIG_FETCHED state, MQTT not connected, wait for the connect
W (7705) tb_ota: WAIT_MQTT state, MQTT not connected, wait for the connect
W (8705) tb_ota: WAIT_MQTT state, MQTT not connected, wait for the connect

[ESP-Marius]

As mentioned earlier, this happens because Thingboard isn't following the MQTT specifications.

If you want to change the header check to match Thingboard's headers you can try to apply the diff I've attached. Go to the esp-mqtt folder in your project and do

Code: Select all

git apply PATH_TO_THINGBOARD_HEADERFIX

[Palonso]

UPDATE: I came up with an idea to avoid the header problem.

I found that the headers are compared/analysed in a function called: int mqtt_has_valid_msg_hdr(uint8_t *buffer, uint16_t length)
which is located in $HOME/esp/esp-idf/components/mqtt/esp-mqtt/lib/mqtt_msg.c file.

Code: Select all

int mqtt_has_valid_msg_hdr(uint8_t *buffer, uint16_t length)
{
    int qos, dup;

    if (length < 1) {
        return 0;
    }
    switch (mqtt_get_type(buffer)) {
    case MQTT_MSG_TYPE_CONNECT:     //0x10
    case MQTT_MSG_TYPE_CONNACK:     //0x20
    case MQTT_MSG_TYPE_PUBACK:      //0x40
    case MQTT_MSG_TYPE_PUBREC:      //0x50
    case MQTT_MSG_TYPE_PUBCOMP:     //0x70
    case MQTT_MSG_TYPE_PINGREQ:     //0xC0
    case MQTT_MSG_TYPE_PINGRESP:    //0xD0
    case MQTT_MSG_TYPE_DISCONNECT:  //0xE0
        return (buffer[0] & 0x0f) == 0;  /* all flag bits are 0 */
//-----------------These are the headers that i had problems------------------
    case MQTT_MSG_TYPE_SUBACK:      //0x90
    case MQTT_MSG_TYPE_UNSUBACK:    //0xB0
        if ((buffer[0] & 0x0f) == 0)
        {
          return (buffer[0] & 0x0f) == 0;
        }
        else if ((buffer[0] & 0x0f) == 0x02)
        {
          return (buffer[0] & 0x0f) == 0x02;  /* only bit 1 is set */
        }
        else
          return 0;
//--------------------------------End of my "solution"---------------------------------
    case MQTT_MSG_TYPE_PUBREL:      //0x60
    case MQTT_MSG_TYPE_SUBSCRIBE:   //0x80
    case MQTT_MSG_TYPE_UNSUBSCRIBE: //0xA0
        return (buffer[0] & 0x0f) == 0x02;  /* only bit 1 is set */
    case MQTT_MSG_TYPE_PUBLISH:     //0x30
        qos = mqtt_get_qos(buffer);
        dup = mqtt_get_dup(buffer);
        /*
         * there is no qos=3  [MQTT-3.3.1-4]
         * dup flag must be set to 0 for all qos=0 messages [MQTT-3.3.1-2]
         */
        return (qos < 3) && ((qos > 0) || (dup == 0));
    default:
        return 0;
    }
}

Basically what i did is adding the headers that i receive (assuming they are correct) and filtered them as correct.
Now the problem is that the message is not published, it's supposed that it passes the headers problem but looks like is not working the publish function itself.

PS: In order to check the headers i changed the code from $HOME/esp/esp-idf/components/mqtt/esp-mqtt/mqtt_client.c in the function static int mqtt_message_receive(esp_mqtt_client_handle_t client, int read_poll_timeout_ms) and added this lines:

Code: Select all

/*
         * Verify the flags and act according to MQTT protocol: close connection
         * if the flags are set incorrectly.
         */

        ESP_LOGE(TAG, "buf=0x%x y buf_type = 0x%x", *buf, mqtt_get_type(buf));
        
        if (!mqtt_has_valid_msg_hdr(buf, read_len)) {
            ESP_LOGE(TAG, "%s: received a message with an invalid header=0x%x", __func__, *buf);
            goto err;
        }

I hope someone comes with an idea of how to fix this problem of publish in Thingsboard

This solution I proposed also works, not sure if opening a pull request on github or just doing the change "under your own risk" if you have to, but definitely this is not solved by changing the IDF version.

[ESP-Marius]

UPDATE: I came up with an idea to avoid the header problem.

I found that the headers are compared/analysed in a function called: int mqtt_has_valid_msg_hdr(uint8_t *buffer, uint16_t length)
which is located in $HOME/esp/esp-idf/components/mqtt/esp-mqtt/lib/mqtt_msg.c file.

Code: Select all

int mqtt_has_valid_msg_hdr(uint8_t *buffer, uint16_t length)
{
    int qos, dup;

    if (length < 1) {
        return 0;
    }
    switch (mqtt_get_type(buffer)) {
    case MQTT_MSG_TYPE_CONNECT:     //0x10
    case MQTT_MSG_TYPE_CONNACK:     //0x20
    case MQTT_MSG_TYPE_PUBACK:      //0x40
    case MQTT_MSG_TYPE_PUBREC:      //0x50
    case MQTT_MSG_TYPE_PUBCOMP:     //0x70
    case MQTT_MSG_TYPE_PINGREQ:     //0xC0
    case MQTT_MSG_TYPE_PINGRESP:    //0xD0
    case MQTT_MSG_TYPE_DISCONNECT:  //0xE0
        return (buffer[0] & 0x0f) == 0;  /* all flag bits are 0 */
//-----------------These are the headers that i had problems------------------
    case MQTT_MSG_TYPE_SUBACK:      //0x90
    case MQTT_MSG_TYPE_UNSUBACK:    //0xB0
        if ((buffer[0] & 0x0f) == 0)
        {
          return (buffer[0] & 0x0f) == 0;
        }
        else if ((buffer[0] & 0x0f) == 0x02)
        {
          return (buffer[0] & 0x0f) == 0x02;  /* only bit 1 is set */
        }
        else
          return 0;
//--------------------------------End of my "solution"---------------------------------
    case MQTT_MSG_TYPE_PUBREL:      //0x60
    case MQTT_MSG_TYPE_SUBSCRIBE:   //0x80
    case MQTT_MSG_TYPE_UNSUBSCRIBE: //0xA0
        return (buffer[0] & 0x0f) == 0x02;  /* only bit 1 is set */
    case MQTT_MSG_TYPE_PUBLISH:     //0x30
        qos = mqtt_get_qos(buffer);
        dup = mqtt_get_dup(buffer);
        /*
         * there is no qos=3  [MQTT-3.3.1-4]
         * dup flag must be set to 0 for all qos=0 messages [MQTT-3.3.1-2]
         */
        return (qos < 3) && ((qos > 0) || (dup == 0));
    default:
        return 0;
    }
}

Basically what i did is adding the headers that i receive (assuming they are correct) and filtered them as correct.
Now the problem is that the message is not published, it's supposed that it passes the headers problem but looks like is not working the publish function itself.

PS: In order to check the headers i changed the code from $HOME/esp/esp-idf/components/mqtt/esp-mqtt/mqtt_client.c in the function static int mqtt_message_receive(esp_mqtt_client_handle_t client, int read_poll_timeout_ms) and added this lines:

Code: Select all

/*
         * Verify the flags and act according to MQTT protocol: close connection
         * if the flags are set incorrectly.
         */

        ESP_LOGE(TAG, "buf=0x%x y buf_type = 0x%x", *buf, mqtt_get_type(buf));
        
        if (!mqtt_has_valid_msg_hdr(buf, read_len)) {
            ESP_LOGE(TAG, "%s: received a message with an invalid header=0x%x", __func__, *buf);
            goto err;
        }

I hope someone comes with an idea of how to fix this problem of publish in Thingsboard

This solution I proposed also works, not sure if opening a pull request on github or just doing the change "under your own risk" if you have to, but definitely this is not solved by changing the IDF version.

Hopefully Thingboard will fix this issue on their end soon: https://github.com/thingsboard/thingsboard/issues/1668. I don't think we will accept any PRs to fix this unfortunately, as there is nothing to fix on the IDF side. Adding a workaround to the codebase just because some other library doesn't follow the specification is a bad idea IMO.

[espnewbie]

Thanks ESP-Marius and Polosa both of your instructions help me it is now working.

[1076934228]

As mentioned earlier, this happens because Thingboard isn't following the MQTT specifications.

If you want to change the header check to match Thingboard's headers you can try to apply the diff I've attached. Go to the esp-mqtt folder in your project and do

Code: Select all

git apply PATH_TO_THINGBOARD_HEADERFIX

Thanks ESP-Marius,its working!