search

shamblett / mqtt_client

A server and browser based MQTT client for dart
Other
548 stars 176 forks source link

double packet sent? #486

Closed lorenzosfarra closed 11 months ago

lorenzosfarra commented 11 months ago

Hi,

the company in charge of the server-side processes tells me that I am sending packets twice in the context of aws with certificates. I have tried do debug this situation listening to my own packets via mqttClient.updates!.listen.

I am sending 10 packets each time.

First, the output is this:

I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 1 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 2 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 3 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 4 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 5 with topic is <my/streamt>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 6 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 7 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 8 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 1 with topic is <my/stream>, payload is <--  -->
I/flutter (19708): 
I/flutter (19708): listen messages length 1
I/flutter (19708): EXAMPLE::Change notification:: identified is 9 with topic is <my/stream>, payload is <--  -->

I can only see 1 duplicate with message identifier 1. The simplified code:

mqttClient = MqttServerClient.withPort(
        MQTT_ENDPOINT, deviceClientId, MQTT_PORT);

    /// Add an auto reconnect callback.
    /// This is the 'pre' auto re connect callback, called before the sequence starts.
    mqttClient.onAutoReconnect = onAutoReconnect;

    /// Add an auto reconnect callback.
    /// This is the 'post' auto re connect callback, called after the sequence
    /// has completed. Note that re subscriptions may be occurring when this callback
    /// is invoked. See [resubscribeOnAutoReconnect] above.
    mqttClient.onAutoReconnected = onAutoReconnected;

    /// Add the successful connection callback if you need one.
    /// This will be called after [onAutoReconnect] but before [onAutoReconnected]
    mqttClient.onConnected = onConnected;

    /// Add a subscribed callback, there is also an unsubscribed callback if you need it.
    /// You can add these before connection or change them dynamically after connection if
    /// you wish. There is also an onSubscribeFail callback for failed subscriptions, these
    /// can fail either because you have tried to subscribe to an invalid topic or the broker
    /// rejects the subscribe request.
    mqttClient.onSubscribed = onSubscribed;

    // Set secure
    mqttClient.secure = true;

    // Set Keep-Alive
    mqttClient.keepAlivePeriod = 20;

    // Set the protocol to V3.1.1 for AWS IoT Core, if you fail to do this you will not receive a connect ack with the response code
    mqttClient.setProtocolV311();

    /// Set auto reconnect
    mqttClient.autoReconnect = true;

    // logging if you wish
    mqttClient.logging(on: MQTT_LOGGING_ENABLED);

    // Set up the context
    mqttClient.securityContext = _getSecurityContext(certificate);

    // Setup the connection Message
    final connMess =
        MqttConnectMessage().withClientIdentifier(deviceClientId).startClean();

       mqttClient.connectionMessage = connMess;

      mqttClient.onDisconnected = onDisconnected;

      await MqttUtilities.asyncSleep(1);

       mqttClient.subscribe("my/stream", MqttQos.atLeastOnce);

      mqttClient.updates!.listen((List<MqttReceivedMessage<MqttMessage?>>? c) {

        print("listen messages length ${c?.length}");

        var cc = c![0];
        final recMess = c![0].payload as MqttPublishMessage;
        final pt =
        MqttPublishPayload.bytesToStringAsString(recMess.payload.message);
        print(
            'EXAMPLE::Change notification:: identified is ${recMess.variableHeader?.messageIdentifier} with topic is <${c[0].topic}>, payload is <-- $pt -->');
        print('');
      });

      var payload = buildMessagePayload(
            mqttPacketPlatformInfo, session, packets, index);

    int packageId =
        mqttClient.publishMessage(topic, MqttQos.atLeastOnce, payload);

      [...]

    static Uint8Buffer buildMessagePayload(
      MqttPacketPlatformInfo packetPlatformInfo,
      SessionDto session,
      List<Packet> valuesPackets,
      int index) {
    final MqttClientPayloadBuilder builder = MqttClientPayloadBuilder();

    int packetStartAt = valuesPackets[0].sentAt;
    int packetStopAt = valuesPackets[valuesPackets.length - 1].sentAt;

    List<int> values = valuesPackets.map((val) => val.value).toList();

    String compressedValues = gzipAndBase64Encode(values.toString());

   PacketToSend valPacketToSend = PacketToSend(
        tsStart: packetStartAt,
        tsStop: packetStopAt,
        data: compressedValues,
        );

    builder.addString(valPacketToSend.toJson());

    var payload = builder.payload!;
    builder.clear();

    return payload;

  }

I am at the first experience with mqtt, but it seems to me that only one packet is sent twice (and should be acceptable because of atLeastOnce). Can you please confirm this?

Another strange thing is that I am unable to get back the payload in the listen(), it's always empty. But they receive it.

Another note is: packageId is incremented from 1 to N, but in the listen the message identifier always have from 1 to 10.

I am a bit lot right now. Can you please give me an hint?

Thanks for your great work.

lorenzosfarra commented 11 months ago

Found why it's empty, builder.clear(); in the wrong order is the responsible.

Anyway, if possible, it would super helpful to have your opinion regarding the "duplicate packet issue", because it seems impossible to me, being subscribed to the topic.

Thanks again

shamblett commented 11 months ago

Your log above has no output from the client, could you please enable this so I can see what the client is actually doing.

The updates stream is for incoming publish messages, if you want to listen to your publish messages once they have completed the MQTT protocol you should listen on the publish stream, from the API -

/// Published message stream. A publish message is added to this
  /// stream on completion of the message publishing protocol for a Qos level.
  /// Attach listeners only after connect has been called.
  Stream<MqttPublishMessage>? get published =>
      publishingManager != null ? publishingManager!.published.stream : null;
lorenzosfarra commented 11 months ago

Here's the connection and subscription part (there are 3 subscriptions to 3 different streams):

2023-10-08 15:16:24.311686+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.311091 -- MqttClient::connect - Connection timeout period is 5000 milliseconds
2023-10-08 15:16:24.326814+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.326571 -- MqttClient::connect - keep alive is enabled with a value of 20 seconds
2023-10-08 15:16:24.338210+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.337794 -- MqttConnectionKeepAlive:: Initialised with a keep alive value of 20 seconds
2023-10-08 15:16:24.339189+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.338959 -- MqttConnectionKeepAlive:: Disconnect on no ping response is disabled
2023-10-08 15:16:24.342876+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.342678 -- MqttConnectionHandlerBase::connect - server a2rkr5blme9z8p-ats.iot.eu-central-1.amazonaws.com, port 8883
2023-10-08 15:16:24.355590+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.355355 -- SynchronousMqttServerConnectionHandler::internalConnect entered
2023-10-08 15:16:24.356998+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.356855 -- SynchronousMqttServerConnectionHandler::internalConnect - initiating connection try 0, auto reconnect in progress false
2023-10-08 15:16:24.358963+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.358774 -- SynchronousMqttServerConnectionHandler::internalConnect - secure selected
2023-10-08 15:16:24.362844+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.362665 -- SynchronousMqttServerConnectionHandler::internalConnect - calling connect
2023-10-08 15:16:24.365929+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.365755 -- MqttSecureConnection::connect - entered
2023-10-08 15:16:24.392451+0200 Runner[381:29222] flutter: [INFO] BleTaskHandler @onRepeatEvent: Start, sendport is 168359814
2023-10-08 15:16:24.393633+0200 Runner[381:29222] flutter: [INFO] BleTaskHandler @onRepeatEvent: still waiting for onStart to complete, skip.
2023-10-08 15:16:24.773722+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.773372 -- MqttSecureConnection::connect - securing socket
2023-10-08 15:16:24.776988+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.776803 -- MqttSecureConnection::connect - start listening
2023-10-08 15:16:24.778978+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.778810 -- MqttServerConnection::_startListening
2023-10-08 15:16:24.782701+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.782089 -- SynchronousMqttServerConnectionHandler::internalConnect - connection complete
2023-10-08 15:16:24.783017+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.782925 -- SynchronousMqttServerConnectionHandler::internalConnect sending connect message
2023-10-08 15:16:24.792223+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.786313 -- MqttConnectionHandlerBase::sendMessage - MQTTMessage of type MqttMessageType.connect
Header: MessageType = MqttMessageType.connect, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
Connect Variable Header: ProtocolName=MQTT, ProtocolVersion=4, ConnectFlags=Connect Flags: Reserved1=false, CleanStart=true, WillFlag=false, WillQos=MqttQos.atMostOnce, WillRetain=false, PasswordFlag=false, UserNameFlag=false, KeepAlive=20
MqttConnectPayload - client identifier is : dev_3
2023-10-08 15:16:24.848053+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.847818 -- SynchronousMqttServerConnectionHandler::internalConnect - pre sleep, state = Connection status is connecting with return code of noneSpecified and a disconnection origin of none
2023-10-08 15:16:24.998108+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:24.997848 -- MqttConnection::onData
2023-10-08 15:16:25.029465+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.027124 -- MqttServerConnection::_onData - message received MQTTMessage of type MqttMessageType.connectAck
Header: MessageType = MqttMessageType.connectAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 2
Connect Variable Header: TopicNameCompressionResponse={0}, ReturnCode={MqttConnectReturnCode.connectionAccepted}
2023-10-08 15:16:25.031465+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.031267 -- MqttServerConnection::_onData - message available event fired
2023-10-08 15:16:25.039666+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.039449 -- MqttConnectionHandlerBase::_connectAckProcessor
2023-10-08 15:16:25.041322+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.041138 -- MqttConnectionHandlerBase:_connectAckProcessor - state = connected
2023-10-08 15:16:25.042617+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @onConnected OnConnected client callback - Client connection was successful
2023-10-08 15:16:25.042872+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.042770 -- MqttConnectionHandlerBase:: cancelling connect timer
2023-10-08 15:16:25.045339+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.045169 -- SynchronousMqttServerConnectionHandler::internalConnect - post sleep, state = Connection status is connected with return code of connectionAccepted and a disconnection origin of none
2023-10-08 15:16:25.045688+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:25.045620 -- SynchronousMqttServerConnectionHandler::internalConnect exited with state Connection status is connected with return code of connectionAccepted and a disconnection origin of none
2023-10-08 15:16:26.073337+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @connectMQTTClient Connection status is connected with return code of connectionAccepted and a disconnection origin of none
2023-10-08 15:16:26.095658+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.093138 -- MqttConnectionHandlerBase::sendMessage - MQTTMessage of type MqttMessageType.subscribe
Header: MessageType = MqttMessageType.subscribe, Duplicate = false, Retain = false, Qos = MqttQos.atLeastOnce, Size = 0
Subscribe Variable Header: MessageIdentifier={1}
Payload: Subscription [{1}]
{{ Topic={ac/streams/dev_3/heart}, Qos={MqttQos.atLeastOnce} }}
2023-10-08 15:16:26.101408+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.100982 -- MqttConnectionHandlerBase::sendMessage - MQTTMessage of type MqttMessageType.subscribe
Header: MessageType = MqttMessageType.subscribe, Duplicate = false, Retain = false, Qos = MqttQos.atLeastOnce, Size = 0
Subscribe Variable Header: MessageIdentifier={2}
Payload: Subscription [{1}]
{{ Topic={ac/streams/dev_3/breath}, Qos={MqttQos.atLeastOnce} }}
2023-10-08 15:16:26.124315+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.123999 -- MqttConnectionHandlerBase::sendMessage - MQTTMessage of type MqttMessageType.subscribe
Header: MessageType = MqttMessageType.subscribe, Duplicate = false, Retain = false, Qos = MqttQos.atLeastOnce, Size = 0
Subscribe Variable Header: MessageIdentifier={3}
Payload: Subscription [{1}]
{{ Topic={ac/streams/dev_3/temperature}, Qos={MqttQos.atLeastOnce} }}
2023-10-08 15:16:26.125403+0200 Runner[381:29222] flutter: [INFO] BleTaskHandler @initMqttClient connection state: true
2023-10-08 15:16:26.411455+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.410210 -- MqttConnection::onData
2023-10-08 15:16:26.419309+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.417856 -- MqttServerConnection::_onData - message received MQTTMessage of type MqttMessageType.subscribeAck
Header: MessageType = MqttMessageType.subscribeAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 3
SubscribeAck Variable Header: MessageIdentifier={1}
Payload: Qos grants [{1}]
{{ Grant={MqttQos.atLeastOnce} }}
2023-10-08 15:16:26.420210+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.420062 -- MqttServerConnection::_onData - message available event fired
2023-10-08 15:16:26.424031+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.423844 -- MqttConnectionHandlerBase::messageAvailable - message type is MqttMessageType.subscribeAck
2023-10-08 15:16:26.428258+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @onSubscribed Subscription confirmed for topic ac/streams/dev_3/heart
2023-10-08 15:16:26.431820+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.431655 -- MqttConnection::onData
2023-10-08 15:16:26.432786+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.432510 -- MqttServerConnection::_onData - message received MQTTMessage of type MqttMessageType.subscribeAck
Header: MessageType = MqttMessageType.subscribeAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 3
SubscribeAck Variable Header: MessageIdentifier={2}
Payload: Qos grants [{1}]
{{ Grant={MqttQos.atLeastOnce} }}
2023-10-08 15:16:26.433175+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.433075 -- MqttServerConnection::_onData - message available event fired
2023-10-08 15:16:26.434033+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.433895 -- MqttConnectionHandlerBase::messageAvailable - message type is MqttMessageType.subscribeAck
2023-10-08 15:16:26.434959+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @onSubscribed Subscription confirmed for topic ac/streams/dev_3/breath
2023-10-08 15:16:26.437687+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.437514 -- MqttConnection::onData
2023-10-08 15:16:26.438843+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.438280 -- MqttServerConnection::_onData - message received MQTTMessage of type MqttMessageType.subscribeAck
Header: MessageType = MqttMessageType.subscribeAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 3
SubscribeAck Variable Header: MessageIdentifier={3}
Payload: Qos grants [{1}]
{{ Grant={MqttQos.atLeastOnce} }}
2023-10-08 15:16:26.439494+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.439373 -- MqttServerConnection::_onData - message available event fired
2023-10-08 15:16:26.441206+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:26.441019 -- MqttConnectionHandlerBase::messageAvailable - message type is MqttMessageType.subscribeAck
2023-10-08 15:16:26.442185+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @onSubscribed Subscription confirmed for topic ac/streams/dev_3/temperature

sending a message

2023-10-08 15:16:49.517236+0200 Runner[381:29222] flutter: sessionToSendQueue before 250
2023-10-08 15:16:49.517505+0200 Runner[381:29222] flutter: ecg before 3654
2023-10-08 15:16:49.519161+0200 Runner[381:29222] flutter: sessionToSendQueue after 250
2023-10-08 15:16:49.520488+0200 Runner[381:29222] flutter: ecg after 3404
2023-10-08 15:16:49.585972+0200 Runner[381:29222] flutter: [INFO] MqttPacketEncoder MqttPacketEncoder @buildEcgMessage sending message {"ecg":{"device_id":"dev_3_","username":"lorenzo","frequency":250,"ts_start":1696770989564,"ts_stop":1696770990523,"data":"H4sIAAAAAAAAE+2Oyw0DIQxEW6EAkPzBNq4lSv9tZIA97EbKLUcO8OzxjOFFtTSu5UITHKulay0SuLrXooIioLKj0MTVlsZEGLccSLP5mDsksII150AEoRYjkbLIaTXGOERWXJkCj7JYuN96JbI1J8m4+9Lp2Q+nR07XV5SGLR+Fbrra1iV33y/f2Lkkv2hf7D/0w8PDw8PDv/D9AQslQdeLBwAA","backup_counter":1,"app_version":"1.0.0","phone_model":"iPhone","os_version":"12.5.7","session_identification_code":"dev_3_2"}} and values [0, -1, 0, -1, -2, -5, 43, 273, 46, 323, 75, 163, 393, -323, 1006, -980, 1568, -1272, 1396, -225, -789, 3579, -9512, 72223, 131071, 125766, 131071, 130053, 130297, 131071, 129607, 131071, 129860, 131071, 130380, 130857, 130737, 130635, 130829, 130640, 130881, 130906, 130905, 130905, 130904, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905, 130905]
2023-10-08 15:16:49.700909+0200 Runner[381:29222] flutter: [INFO] MqttPacketEncoder validation packet valid
2023-10-08 15:16:49.705255+0200 Runner[381:29222] flutter: [INFO] MqttPacketEncoder Build packet {"ecg":{"device_id":"dev_3","username":"lorenzo","frequency":250,"ts_start":1696770989564,"ts_stop":1696770990523,"data":"H4sIAAAAAAAAE+2Oyw0DIQxEW6EAkPzBNq4lSv9tZIA97EbKLUcO8OzxjOFFtTSu5UITHKulay0SuLrXooIioLKj0MTVlsZEGLccSLP5mDsksII150AEoRYjkbLIaTXGOERWXJkCj7JYuN96JbI1J8m4+9Lp2Q+nR07XV5SGLR+Fbrra1iV33y/f2Lkkv2hf7D/0w8PDw8PDv/D9AQslQdeLBwAA","backup_counter":1,"app_version":"1.0.0","phone_model":"iPhone","os_version":"12.5.7","session_identification_code":"dev_3_2"}}
2023-10-08 15:16:49.706498+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @_sendEcgBrtMessage hashcode is 947649722
2023-10-08 15:16:49.711780+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:49.711599 -- PublishingManager::publish - entered with topic ac/streams/dev_3/heart
2023-10-08 15:16:49.721878+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:49.717514 -- MqttConnectionHandlerBase::sendMessage - MQTTMessage of type MqttMessageType.publish
Header: MessageType = MqttMessageType.publish, Duplicate = false, Retain = false, Qos = MqttQos.atLeastOnce, Size = 0
Publish Variable Header: TopicName={ac/streams/dev_3/heart}, MessageIdentifier={4}, VH Length={0}
Payload: {483 bytes={<123><34><101><99><103><34><58><123><34><100><101><118><105><99><101><95><105><100><34><58><34><97><99><121><51><95><56><68><50><66><55><56><34><44><34><117><115><101><114><110><97><109><101><34><58><34><108><111><114><101><110><122><111><34><44><34><102><114><101><113><117><101><110><99><121><34><58><50><53><48><44><34><116><115><95><115><116><97><114><116><34><58><49><54><57><54><55><55><48><57><56><57><53><54><52><44><34><116><115><95><115><116><111><112><34><58><49><54><57><54><55><55><48><57><57><48><53><50><51><44><34><100><97><116><97><34><58><34><72><52><115><73><65><65><65><65><65><65><65><65><69><43><50><79><121><119><48><68><73><81><120><69><87><54><69><65><107><80><122><66><78><113><52><108><83><118><57><116><90><73><65><57><55><69><98><75><76><85><99><79><56><79><122><120><106><79><70><70><116><84><83><117><53><85><73><84><72><75><117><108><97><121><48><83><117><76><114><88><111><111><73><105><111><76><75><106><48><77><84><86><108><115><90><69><71><76><99><99><83><76><80><53><109><68><115><107><115><73><73><49><53><48><65><69><111><82><89><106><107><98><76><73><97><84><88><71><79><69><82><87><88><74><107><67><106><55><74><89><117><78><57><54><74><98><73><49><74><56><109><52><43><57><76><112><50><81><43><110><82><48><55><88><86><53><83><71><76><82><43><70><98><114><114><97><49><105><86><51><51><121><47><102><50><76><107><107><118><50><104><102><55><68><47><48><119><56><80><68><119><56><80><68><118><47><68><57><65><81><115><108><81><100><101><76><66><119><65><65><34><44><34><98><97><99><107><117><112><95><99><111><117><110><116><101><114><34><58><49><44><34><97><112><112><95><118><101><114><115><105><111><110><34><58><34><49><46><48><46><48><34><44><34><112><104><111><110><101><95><109><111><100><101><108><34><58><34><105><80><104><111><110><101><34><44><34><111><115><95><118><101><114><115><105><111><110><34><58><34><49><50><46><53><46><55><34><44><34><115><101><115><115><105><111><110><95><105><100><101><110><116><105><102><105><99><97><116><105><111><110><95><99><111><100><101><34><58><34><97><99><121><51><45><56><68><50><66><55><56><95><50><34><125><125>
2023-10-08 15:16:49.730539+0200 Runner[381:29222] flutter: [INFO] MQTTClientManager @_sendEcgBrtMessage Package published to ac/streams/dev_3/heart: 4 with hashcode 947649722

And listening

2023-10-08 15:16:50.491507+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.491362 -- MqttServerConnection::_onData - message available event fired
2023-10-08 15:16:50.492274+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.492160 -- MqttConnectionHandlerBase::messageAvailable - message type is MqttMessageType.publish
2023-10-08 15:16:50.495588+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.495400 -- PublishingManager::handlePublish - publish received from broker with topic ac/streams/dev_3/heart
2023-10-08 15:16:50.503120+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.502879 -- MqttConnectionHandlerBase::sendMessage - MQTTMessage of type MqttMessageType.publishAck
Header: MessageType = MqttMessageType.publishAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
PublishAck Variable Header: MessageIdentifier={1}
2023-10-08 15:16:50.517027+0200 Runner[381:29222] flutter: listen messages length 1
2023-10-08 15:16:50.525830+0200 Runner[381:29222] flutter: EXAMPLE::Change notification:: identified is 1 with topic is <ac/streams/dev_3/heart>, payload is <-- {"ecg":{"device_id":"dev_3","username":"lorenzo","frequency":250,"ts_start":1696770989564,"ts_stop":1696770990523,"data":"H4sIAAAAAAAAE+2Oyw0DIQxEW6EAkPzBNq4lSv9tZIA97EbKLUcO8OzxjOFFtTSu5UITHKulay0SuLrXooIioLKj0MTVlsZEGLccSLP5mDsksII150AEoRYjkbLIaTXGOERWXJkCj7JYuN96JbI1J8m4+9Lp2Q+nR07XV5SGLR+Fbrra1iV33y/f2Lkkv2hf7D/0w8PDw8PDv/D9AQslQdeLBwAA","backup_counter":1,"app_version":"1.0.0","phone_model":"iPhone","os_version":"12.5.7","session_identification_code":"dev_3_2"}} -->
2023-10-08 15:16:50.526262+0200 Runner[381:29222] flutter:
2023-10-08 15:16:50.547408+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.547229 -- MqttConnection::onData
2023-10-08 15:16:50.548943+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.548743 -- MqttServerConnection::_onData - message received MQTTMessage of type MqttMessageType.publishAck
Header: MessageType = MqttMessageType.publishAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 2
PublishAck Variable Header: MessageIdentifier={7}
MqttConnectionHandlerBase::messageAvailable - message type is MqttMessageType.publishAck
2023-10-08 15:16:50.456031+0200 Runner[381:29222] flutter: 1-2023-10-08 15:16:50.455853 -- PublishingManager::handlePublishAcknowledgement for message id 4

I have cut a bit of logs because I am not sending a single one, but it should everything related to the single packet.

Looking for "handlePublishAcknowledgement for message id 4" I only have 1 results.

Regarding the published thanks, I was aware of that, but I wanted to put myself in the "client" situation, listening to the topic.

Let me know if you need any other info.

Thanks

shamblett commented 11 months ago

Sorry I'm losing my thread here, where in the above log extracts does it show you sending a duplicate message? All I can see here is that after your subscriptions you publish a message with id 4 and you get a pub ack for message identifier 1, followed by 7, followed by 4. I would be expecting to see a publish message with the same message identifier twice would I not?

Looking for "handlePublishAcknowledgement for message id 4" I only have 1 results.

Isn't this what you would expect?

The best way to debug this is to look at your AWS server logs and see if the client is sending duplicate publish messages(with duplicate not set of course) or ask your server guys for this, they presumably have some log evidence.

lorenzosfarra commented 11 months ago

Thanks anyway, I will look into it with them.

Have a nice day!