[BUG] Random unsolicited publish from topic

[law-ko]

Hello,

We are using AWS IoT Thing Shadow mechanism which utilizes the delta technique. When we frequently control the device and when the ESP32 is subscribed to the delta topic, it will randomly not accept the publish message by Received an unsolicited publish from topic $aws/things/thingName/shadow/name/shadowName/update/delta, which leads to not parsing the incoming message by prvIncomingPublishCallback.

static void prvIncomingPublishCallback( void * pvIncomingPublishCallbackContext,
                                        MQTTPublishInfo_t * pxPublishInfo )
{
    IncomingPublishCallbackContext_t * pxIncomingPublishCallbackContext = ( IncomingPublishCallbackContext_t * ) pvIncomingPublishCallbackContext;

    /* Create a message that contains the incoming MQTT payload to the logger,
     * terminating the string first. */
    if( pxPublishInfo->payloadLength < fleetprovbyclaimconfigSTRING_BUFFER_LENGTH )
    {
        memcpy( ( void * ) ( pxIncomingPublishCallbackContext->pcIncomingPublish ),
                pxPublishInfo->pPayload,
                pxPublishInfo->payloadLength );

        ( pxIncomingPublishCallbackContext->pcIncomingPublish )[ pxPublishInfo->payloadLength ] = 0x00;
    }
    else
    {
        memcpy( ( void * ) ( pxIncomingPublishCallbackContext->pcIncomingPublish ),
                pxPublishInfo->pPayload,
                fleetprovbyclaimconfigSTRING_BUFFER_LENGTH );

        ( pxIncomingPublishCallbackContext->pcIncomingPublish )[ fleetprovbyclaimconfigSTRING_BUFFER_LENGTH - 1 ] = 0x00;
    }

	ESP_LOGI( TAG,
			"Received incoming publish message %s",
			pxIncomingPublishCallbackContext->pcIncomingPublish );

	/* Only parse incoming publish on delta device shadow message. */
	ShadowMessageType_t messageType = ShadowMessageTypeMaxNum;
	if ( SHADOW_SUCCESS == Shadow_MatchTopicString( pxPublishInfo->pTopicName,
													pxPublishInfo->topicNameLength,
													&messageType,
													NULL,
													NULL,
													NULL,
													NULL))
	{
		if ( messageType == ShadowMessageTypeUpdateDelta )
		{
			prvParseIncomingPublish( (char *) pxPublishInfo->pPayload, pxPublishInfo->payloadLength );
		}
	}

	xTaskNotify( pxIncomingPublishCallbackContext->xTaskToNotify,
				pxIncomingPublishCallbackContext->ulNotificationValue,
				eSetValueWithOverwrite );
}

System information

• Hardware board: ESP32-PICO-MINI02
• IDE used: idf.py v5.0.1
• Operating System: Linux

Screenshots or console output

Steps to reproduce bug
Unknown, happens randomly, still investigating the reason behind it.

[ActoryOu]

Hi @law-ko,
Thanks for your feedback. We're looking into it.
If possible, please help share your full console output (without personal info) to help us accerlerate the progress.

Thanks!

[ActoryOu]

I have some questions about this issue.

1. What demo are you running to get this issue?
2. Did you change anything on original source code?
3. Is it possible that the topic subscription is not finished yet? Then MQTT_MatchTopic returns non-match while comparison.

Thanks!
BR,
Actory

[law-ko]

Hi @ActoryOu ,

1. The program is based on: temp_sub_pub_and_led_control_demo
2. No
3. The AWS IoT desired mechanism is designed so that even the device is offline and get back online, it can still receive the shadow delta message and then perform the desired state. If the device is offline and a delta message is set, then the subscribed topic will receive the message once the device is back online. Based on my experience, I do not think this is the case as this happens randomly during the device is online. However, once the device is stuck in this unsolicited publish state, it will not recover unless a power cycle on ESP32.

[ActoryOu]

Hi @law-ko,
I can't find the shadow behavior on that demo in temp_sub_pub_and_led_control_demo.c. Could you tell me what's your configuration on running this demo? And what's happening at that timing? ( For example, is there any other device reporting its state, so it triggers delta message from cloud to device? ) Again, if possible, please help share your full console output.

Thanks again.

[law-ko]

Hi @ActoryOu ,

The only change is the topic that is subscribed to is based on delta mechanism. For example: $aws/things/thingName/shadow/name/shadowName/update/delta. The trigger will be the user tries to control the device remotely, which will send a desired message to the AWS IoT Thing Shadow document. Please see this for reference on desired and reported usage: https://docs.aws.amazon.com/iot/latest/developerguide/iot-device-shadows.html

The console output that I have is attached in the original post. If there are other settings to enable full debug log output please let me know.

Thank you

[ActoryOu]

Hi @law-ko,
I can only find the warning message on the figure. But I'd like to get more information on console, like when did you subscribe to that delta topic.

I'm not sure if I understand the meaning of The only change is the topic that is subscribed to is based on delta mechanism. completely. Could you share what you've done on this?

BTW, if you want, you can post this on FreeRTOS Forum to get more suggestions from others.

Thanks.

[law-ko]

Hi @ActoryOu ,

The subscribe event happens right after the MQTTAgent is connected, below is how it is subscribed:

/* Subscribe to ShadowUpdate delta topics. */
	shadowStatus = Shadow_AssembleTopicString (	ShadowTopicStringTypeUpdateDelta,
												thingName,
												thingNameLength,
												shadowName,
												shadowNameLength,
												pcSubTopicBuffer,
												thingshadowconfigSTRING_BUFFER_LENGTH,
												&outLength );
	pcSubTopicBuffer[outLength] = '\0'; // terminate string for correct strlen

	if( shadowStatus == SHADOW_SUCCESS )
	{
		prvSubscribeToTopic( &xIncomingPublishCallbackContext, xQoS, pcSubTopicBuffer );
	}

Below is how it is being handled when an incoming publish is received:

static void prvIncomingPublishCallback( void * pvIncomingPublishCallbackContext,
                                        MQTTPublishInfo_t * pxPublishInfo )
{
    IncomingPublishCallbackContext_t * pxIncomingPublishCallbackContext = ( IncomingPublishCallbackContext_t * ) pvIncomingPublishCallbackContext;

    /* Create a message that contains the incoming MQTT payload to the logger,
     * terminating the string first. */
    if( pxPublishInfo->payloadLength < fleetprovbyclaimconfigSTRING_BUFFER_LENGTH )
    {
        memcpy( ( void * ) ( pxIncomingPublishCallbackContext->pcIncomingPublish ),
                pxPublishInfo->pPayload,
                pxPublishInfo->payloadLength );

        ( pxIncomingPublishCallbackContext->pcIncomingPublish )[ pxPublishInfo->payloadLength ] = 0x00;
    }
    else
    {
        memcpy( ( void * ) ( pxIncomingPublishCallbackContext->pcIncomingPublish ),
                pxPublishInfo->pPayload,
                fleetprovbyclaimconfigSTRING_BUFFER_LENGTH );

        ( pxIncomingPublishCallbackContext->pcIncomingPublish )[ fleetprovbyclaimconfigSTRING_BUFFER_LENGTH - 1 ] = 0x00;
    }

	ESP_LOGI( TAG,
			"Received incoming publish message %s",
			pxIncomingPublishCallbackContext->pcIncomingPublish );

	/* Only parse incoming publish on delta device shadow message. */
	ShadowMessageType_t messageType = ShadowMessageTypeMaxNum;
	if ( SHADOW_SUCCESS == Shadow_MatchTopicString( pxPublishInfo->pTopicName,
													pxPublishInfo->topicNameLength,
													&messageType,
													NULL,
													NULL,
													NULL,
													NULL))
	{
		if ( messageType == ShadowMessageTypeUpdateDelta )
		{
			prvParseIncomingPublish( (char *) pxPublishInfo->pPayload, pxPublishInfo->payloadLength );
		}
	}

	xTaskNotify( pxIncomingPublishCallbackContext->xTaskToNotify,
				pxIncomingPublishCallbackContext->ulNotificationValue,
				eSetValueWithOverwrite );
}

[manvensh]

Hi @law-ko
Can please provide the following two things.

1. Please set the LIBRARY_LOG_LEVEL to LOG_DEBUG in core_mqtt_config.h and then share your full console output (without personal info)
2. Please share what have you done on this The only change is the topic that is subscribed to is based on delta mechanism.

Thank you

[law-ko]

Hi @law-ko Can please provide the following two things.

1. Please set the LIBRARY_LOG_LEVEL to LOG_DEBUG in core_mqtt_config.h and then share your full console output (without personal info)
2. Please share what have you done on this The only change is the topic that is subscribed to is based on delta mechanism.

Thank you

Hi @manvensh ,

1. Please confirm if you mean by the below settings:

2. This is the topic being subscribed: $aws/things/thingName/shadow/name/shadowName/update/delta

Thank you

[ActoryOu]

Hi @law-ko,
Could you share the entire source code change by github link?
We'd like to look into it.

Thanks.

[ActoryOu]

closing it for now since long time no response. feel free to re-open it if any new finding.