{"action":"opened","issue":{"url":"https://api.github.com/repos/chkr1011/MQTTnet/issues/425","repository_url":"https://api.github.com/repos/chkr1011/MQTTnet","labels_url":"https://api.github.com/repos/chkr1011/MQTTnet/issues/425/labels{/name}","comments_url":"https://api.github.com/repos/chkr1011/MQTTnet/issues/425/comments","events_url":"https://api.github.com/repos/chkr1011/MQTTnet/issues/425/events","html_url":"https://github.com/chkr1011/MQTTnet/issues/425","id":365367151,"node_id":"MDU6SXNzdWUzNjUzNjcxNTE=","number":425,"title":"Duplicated messages","user":{"login":"elmosan","id":33811806,"node_id":"MDQ6VXNlcjMzODExODA2","avatar_url":"https://avatars3.githubusercontent.com/u/33811806?v=4","gravatar_id":"","url":"https://api.github.com/users/elmosan","html_url":"https://github.com/elmosan","followers_url":"https://api.github.com/users/elmosan/followers","following_url":"https://api.github.com/users/elmosan/following{/other_user}","gists_url":"https://api.github.com/users/elmosan/gists{/gist_id}","starred_url":"https://api.github.com/users/elmosan/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/elmosan/subscriptions","organizations_url":"https://api.github.com/users/elmosan/orgs","repos_url":"https://api.github.com/users/elmosan/repos","events_url":"https://api.github.com/users/elmosan/events{/privacy}","received_events_url":"https://api.github.com/users/elmosan/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":0,"created_at":"2018-10-01T09:00:27Z","updated_at":"2018-10-01T09:00:27Z","closed_at":null,"author_association":"NONE","body":"Hi,\r\nIf our application with the MQTTnet client is busy, the client receives messages twice. After an analysis of our logs I noted the following:\r\n\r\nThe \"ApplicationMessageReceived\" event gets triggered when the client sends the PUBREC message. With the MQTT Level QOS 2 - Only Once (http://www.steves-internet-guide.com/understanding-mqtt-qos-2) the event should be triggerd when the PUBREL Messages was received, otherwise the PUBREC will be resend.\r\n\r\nProcessing of double messages causes problems in our application. Detected in the mqttnet versions 2.7.5 and 2.8.2.\r\nThe following Log shows the received event and then the PUBREL and PUBCOMP:\r\n\r\n> 2018-09-19 15:11:28,790 [3] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubRec ThreadId=3 Timestamp=09/19/2018 13:11:28 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:28,791 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< Publish: [Topic=/rtc/data/datacachechangequeueitem] [Payload.Length=136] [QoSLevel=ExactlyOnce] [Dup=False] [Retain=False] [PacketIdentifier=4] ThreadId=7 Timestamp=09/19/2018 13:11:28 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:28,791 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: Rtc Message received (/rtc/data/datacachechangequeueitem)\r\n> 2018-09-19 15:11:29,685 [3] INFO  Infrastructure.RtcMqttMessage - DataCacheChangeQueueItemCommand: Data updated for Id='10767816-1aad-464e-9532-91ffa8e64744'\r\n> 2018-09-19 15:11:29,685 [4] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubRec ThreadId=4 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,686 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< Publish: [Topic=/rtc/data/datacachechangequeueitem] [Payload.Length=136] [QoSLevel=ExactlyOnce] [Dup=False] [Retain=False] [PacketIdentifier=5] ThreadId=7 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,686 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: Rtc Message received (/rtc/data/datacachechangequeueitem)\r\n> 2018-09-19 15:11:29,691 [6] INFO  Infrastructure.RtcMqttMessage - DataCacheChangeQueueItemCommand: Data updated for Id='d1bd3c39-b44c-48cf-9ed6-572fa9b43a90'\r\n> 2018-09-19 15:11:29,692 [4] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubRec ThreadId=4 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,693 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< Publish: [Topic=/rtc/data/datacachechangequeueitem] [Payload.Length=1425] [QoSLevel=ExactlyOnce] [Dup=False] [Retain=False] [PacketIdentifier=6] ThreadId=7 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,693 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: Rtc Message received (/rtc/data/datacachechangequeueitem)\r\n> 2018-09-19 15:11:29,701 [4] INFO  Infrastructure.RtcMqttMessage - DataCacheChangeQueueItemCommand: Data updated for Id='95ab3ea9-f819-41b6-9f71-af144e95ee30'\r\n> 2018-09-19 15:11:29,702 [3] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubRec ThreadId=3 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,702 [4] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< Publish: [Topic=/rtc/data/datacachechangequeueitem] [Payload.Length=2839] [QoSLevel=ExactlyOnce] [Dup=False] [Retain=False] [PacketIdentifier=7] ThreadId=4 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,702 [4] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: Rtc Message received (/rtc/data/datacachechangequeueitem)\r\n> 2018-09-19 15:11:29,707 [3] INFO  Infrastructure.RtcMqttMessage - DataCacheChangeQueueItemCommand: Data updated for Id='Alpha550'\r\n> 2018-09-19 15:11:29,707 [6] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubRec ThreadId=6 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,708 [3] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< PubRel ThreadId=3 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,708 [6] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubComp ThreadId=6 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,709 [4] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< PubRel ThreadId=4 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,709 [6] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubComp ThreadId=6 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,709 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< PubRel ThreadId=7 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,710 [6] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubComp ThreadId=6 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,710 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< PubRel ThreadId=7 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,710 [6] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: TX >>> PubComp ThreadId=6 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter\r\n> 2018-09-19 15:11:29,711 [7] DEBUG Infrastructure.RtcMqttMessage - RtcMqttBrokerAccess: RX <<< PubRel ThreadId=7 Timestamp=09/19/2018 13:11:29 MqttClient.MqttChannelAdapter"}}
{"actor":{"display_login":"elmosan"}}