Mqtt publish qos 0 working but when using qos 1, return publish failure

Libraries
1

I ported the FreeRTOS 20210700 to STM32, when I used none-agent version mqtt to publish to AWS, if set qos0, then it is working fine and reliable. But when I use qos1, the it shows publish failed.
When I use the OTA which is agent version of MQTT, the publish is failed, I found it is using qos1 too.
May I know if any setting affect this?

requestJob_Mqtt:Failed to publish MQTT message:publish returned error: OtaMqttStatus_t=OtaMqttPublishFailed
Failed to subscribe to MQTT topic: subscribe returned error: OtaMqttStatus_t=OtaMqttSubscribeFailed, topic=$aws/things/350999901/jobs/notify-next

2

Which STM32 platfrom are you porting to? Can you enable MQTT debug logs and share logs? You’ll need to changes your core_mqtt_config.h file: https://github.com/aws/amazon-freertos/blob/main/vendors/st/boards/stm32l475_discovery/aws_demos/config_files/core_mqtt_config.h#L44

Thanks.

3

thanks aggarg, I port to STM32H7 with LwIP stack. I can connect to AWS and report using none-agent mqtt version with qos 0.
then I run the code of agent version mqtt:

here is some logs when I run the simple_sub_pub_demo.c
It seems the prvPublishCommandCallback never got called.
I know it maybe my port issue as the windows simulator works, so it should not be a problem of mqtt agent. Any hints is great.

simple_sub_pub_demo. +387  prvSubscribeToTopic       Sending subscribe request to agent for topic filter: /filter/Publisher0 with id 1
simple_sub_pub_demo. +414  prvSubscribeToTopic       Received subscribe ack for topic /filter/Publisher0 containing ID 1
simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 0" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 0 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 0

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 1" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 1 to complete.
configASSERT:../Core/MQTT_Agent/simple_sub_pub_demo.c:513
4

prvPublishCommandCallback should get called from here which should get called when MQTT_ProcessLoop is called here. Are you calling MQTTAgent_CommandLoop function in a loop like here?

Can you set breakpoints at above three locations to see where is it failing?

Thanks.

5

it appears stuck in MQTT_ProcessLoop. But first time call, it is OK, then not returning.
I suspect there is some socket option on receives etc, as I change to use LwIP stack.
here is the logs: (Interesting to see number 8 package actual reaches AWS IoT )
It looks like QoS 0 does not need reply, so it works, but when get QoS 1, it needs ACK, then stop working. Stuck in readFunc in MQTT_GetIncomingPacketTypeAndLength:
Really appreciate if can shot further light on it. thanks
MQTTStatus_t MQTT_GetIncomingPacketTypeAndLength( TransportRecv_t readFunc,
NetworkContext_t * pNetworkContext,
MQTTPacketInfo_t * pIncomingPacket )
{

else
{
    /* Read a single byte. */

//hang here
bytesReceived = readFunc( pNetworkContext,
&( pIncomingPacket->type ),
1U );

mtd_mqtt_agent.c     +524  prvSocketConnect          prvConnectToServerWithBackoffRetries
sockets_wrapper.c    +155  Sockets_Connect           Established TCP connection with a2l4ym2rlvj63k-ats.iot.ap-southeast-2.amazonaws.com. socket=0, ip=-898623485
core_mqtt.c          +886  receivePacket             Packet received. ReceivedBytes=2.
core_mqtt_serializer +969  deserializeConnack        CONNACK session present bit not set.
core_mqtt_serializer +911  logConnackResponse        Connection accepted.
core_mqtt.c          +1566 receiveConnack            Received MQTT CONNACK successfully from broker.
core_mqtt.c          +1832 MQTT_Connect              MQTT connection established with the broker.
mtd_mqtt_agent.c     +393  prvMQTTConnect            Session present: 0

simple_sub_pub_demo. +387  prvSubscribeToTopic       Sending subscribe request to agent for topic filter: /filter/Publisher0 with id 1
core_mqtt.c          +886  receivePacket             Packet received. ReceivedBytes=3.
simple_sub_pub_demo. +414  prvSubscribeToTopic       Received subscribe ack for topic /filter/Publisher0 containing ID 1
simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 0" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 0 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 0

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 1" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 1 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 1

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 2" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 2 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 2

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 3" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 3 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 3

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 4" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 4 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 4

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 5" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 5 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 5

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 6" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 6 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 6

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 7" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 7 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 0, 7

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 8" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 8 to complete.
core_mqtt_serializer +2399 MQTT_GetIncomingPacketTyp A single byte was not read from the transport: transportStatus=-30848.
core_mqtt.c          +1322 receiveSingleIteration    Receiving incoming packet length failed. Status=MQTTRecvFailed
core_mqtt.c          +2194 MQTT_ProcessLoop          Exiting process loop due to failure: ErrorStatus=MQTTRecvFailed
core_mqtt_agent.c    +1025 MQTTAgent_CommandLoop     MQTT operation failed with status MQTTRecvFailed

mtd_mqtt_agent.c     +676  prvMQTTAgentTask          WARN:  MQTTAgent_CommandLoop return 4
mtd_mqtt_agent.c     +616  prvSocketDisconnect       Disconnecting TLS connection.

mtd_mqtt_agent.c     +524  prvSocketConnect          prvConnectToServerWithBackoffRetries
sockets_wrapper.c    +155  Sockets_Connect           Established TCP connection with a2l4ym2rlvj63k-ats.iot.ap-southeast-2.amazonaws.com. socket=1, ip=-1185728755
core_mqtt.c          +886  receivePacket             Packet received. ReceivedBytes=2.
core_mqtt_serializer +969  deserializeConnack        CONNACK session present bit not set.
core_mqtt_serializer +911  logConnackResponse        Connection accepted.
core_mqtt.c          +1566 receiveConnack            Received MQTT CONNACK successfully from broker.
core_mqtt.c          +1832 MQTT_Connect              MQTT connection established with the broker.
mtd_mqtt_agent.c     +393  prvMQTTConnect            Session present: 0

mtd_mqtt_agent.c     +444  prvHandleResubscribe      Resubscribe to the topic /filter/Publisher0 will be attempted.
core_mqtt.c          +886  receivePacket             Packet received. ReceivedBytes=2.
core_mqtt.c          +1164 handlePublishAcks         Ack packet deserialized with result: MQTTSuccess.
core_mqtt.c          +1177 handlePublishAcks         State record updated. New state=MQTTPublishDone.
simple_sub_pub_demo. +245  prvPublishCommandCallback prvPublishCommandCallback 0.

simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 8, 8

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 9" on topic "/filter/Publisher0"
simple_sub_pub_demo. +505  prvSimpleSubscribePublish Task Publisher0 waiting for publish 9 to complete.
simple_sub_pub_demo. +516  prvSimpleSubscribePublish Demo completed successfully. 8, 9

simple_sub_pub_demo. +490  prvSimpleSubscribePublish Sending publish request to agent with message "Publisher0 publishing message 10" on topic "/filter/Publisher0"
freertos_command_poo +119  Agent_GetCommand          No command structure available.
configASSERT:../Core/MQTT_Agent/simple_sub_pub_demo.c:501
6

Seems like an error in receive. Can you check what this error code means?

You probably need to increaseMQTT_COMMAND_CONTEXTS_POOL_SIZE. For debugging, you can reduce the number of publisher tasks and enable them later once you get one task working.

Seems like you are hitting an assert. What is this assert?

Thanks.

7

Another thing to try. You are right in that QoS1 will definitely take more time because you will need to send a PUBACK to the broker in addition to just receiving the actual message. Although, it seems you mentioned that you are stuck at the recv call, and this can happen when the transport recv function has no configured timeout. Have you enabled LWIP_SO_RCVTIMEO and used netconn_set_recvtimeout to set the recv timeout of the socket as shown in this tutorial? You will likely want to do the same for send.

8

thanks @aggarg and @abrinao ,
today I solved this problem.
The reason is when I port the lwIP, the socket set_option parameter takes the one from FreeRTOS Plus stack. But they have different defines. After I set the socket option timeout correctly, it is working now.
The stuck of recv call is because timeout does not work, and it hang there.
Thanks again.