Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

QOS0 incorrect outbox expiry deletion when MQTT_REPORT_DELETED_MESSAGES is defined (IDFGH-14021) #289

Open
3 tasks done
Totrasmek opened this issue Nov 6, 2024 · 1 comment · May be fixed by #290
Open
3 tasks done

Comments

@Totrasmek
Copy link

Totrasmek commented Nov 6, 2024

Checklist

  • Checked the issue tracker for similar issues to ensure this is not a duplicate
  • Read the documentation to confirm the issue is not addressed there and your configuration is set correctly
  • Tested with the latest version to ensure the issue hasn't been fixed

How often does this bug occurs?

always

Expected behavior

When setting MQTT_REPORT_DELETED_MESSAGES, I expect to receive an MQTT_EVENT_DELETED posted to the event handler when the esp_mqtt_task calls mqtt_delete_expired_messages(client) for each QOS0 message that has been in the outbox > OUTBOX_EXPIRED_TIMEOUT_MS. This is the behaviour for QOS1 and QOS2 messages.

Actual behavior (suspected bug)

When my outbox has only QOS0 messages, I receive no MQTT_EVENT_DELETED posted to the event handler, and only the first message in the outbox is deleted if it has been in the outbox > OUTBOX_EXPIRED_TIMEOUT_MS.

This is because QOS0 messages are given a msg_id of 0 and mqtt_delete_expired_messages stops deleting outbox items once their msg_id is 0 as seen here:

while ((msg_id = outbox_delete_single_expired(client->outbox, platform_tick_get_ms(), OUTBOX_EXPIRED_TIMEOUT_MS)) > 0) {
        client->event.event_id = MQTT_EVENT_DELETED;
        client->event.msg_id = msg_id;
        if (esp_mqtt_dispatch_event(client) != ESP_OK) {
            ESP_LOGE(TAG, "Failed to post event on deleting message id=%d", msg_id);
        }
    }

This might be easily fixed by changing the conditional from > to >= on the msg_id

Error logs or terminal output

No response

Steps to reproduce the behavior

  1. Ensure your event handler will log MQTT_EVENT_DELETED
  2. Turn on MQTT_REPORT_DELETED_MESSAGES
  3. Log the outbox size in esp_mqtt_task just before and after mqtt_delete_expired_messages(client)
  4. Continuously enqueue to the outbox QOS0 messages
  5. Add some high latency to the network to force messages to reach past the OUTBOX_EXPIRED_TIMEOUT_MS by using a local broker and simulated latency through a command like sudo tc qdisc add dev wlp0s20f3 root netem delay 2000ms
  6. Observe that you will never see MQTT_EVENT_DELETED
  7. Observe that the outbox will only ever drop by the size of a single message at a time, even though your outbox is likely filled with many expired messages.

Project release version

I am using commit cac1552 shipped with ESP-IDF v5.2,v5.3 and v5.4

System architecture

other (details in Additional context)

Operating system

Linux

Operating system version

Ubuntu 22.04

Shell

Bash

Additional context

No response

@github-actions github-actions bot changed the title QOS0 incorrect outbox expiry deletion when MQTT_REPORT_DELETED_MESSAGES is defined QOS0 incorrect outbox expiry deletion when MQTT_REPORT_DELETED_MESSAGES is defined (IDFGH-14021) Nov 6, 2024
@euripedesrocha
Copy link
Collaborator

Hi @Totrasmek thanks for reporting and providing the PR with the fix. I'll review and test it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants