search

dotnet / MQTTnet

MQTTnet is a high performance .NET library for MQTT based communication. It provides a MQTT client and a MQTT server (broker). The implementation is based on the documentation from http://mqtt.org/.
MIT License
4.51k stars 1.07k forks source link

Communication exception while processing client packets #162

Closed R3dNinja closed 6 years ago

R3dNinja commented 6 years ago

I am working with the MQTTnet test applications, just to get an understanding of what is going on. I am running into an issue with the Server where the Communication is dropped on the last message received. I am using the ServerTest from MQTTnet.TestApp.NetCore running local. I have a very simple Client, also using MQTTnet that loops through 0 - 8, incrementing the text of the payload each loop. After the loop, I have the same client publish to a different topic, this fails. I have also tried without the extra message out of the loop and have the same issue. The last message always produces a warning and the server never publishes the message. Below is the console window of the error (just the last 2 messages from the loop and the extra message at the end). `

[2018-01-22T11:25:46.8775786-06:00] [16] [MqttRetainedMessagesManager] [Info]: Client 'testbed' set retained message for topic '/DWG/running'. 'testbed' reported '/DWG/running' > 'username7'>> [2018-01-22T11:25:46.8785824-06:00] [16] [MqttChannelAdapter] [Verbose]: TX >>> PubRec [Timeout=00:00:15] [2018-01-22T11:25:46.8788108-06:00] [16] [MqttChannelAdapter] [Verbose]: RX <<< PubRel [2018-01-22T11:25:46.8788108-06:00] [16] [MqttChannelAdapter] [Verbose]: TX >>> PubComp [Timeout=00:00:15] [2018-01-22T11:25:46.8788108-06:00] [16] [MqttChannelAdapter] [Verbose]: RX <<< Publish: [Topic=/DWG/running] [Payload.Length=9] [QoSLevel=ExactlyOnce] [Dup=False] [Retain=True] [PacketIdentifier=9] Newtonsoft.Json.JsonReaderException: Error parsing undefined value. Path '', line 1, position 1. at Newtonsoft.Json.JsonTextReader.ParseUndefined() at Newtonsoft.Json.JsonTextReader.ParseValue() at Newtonsoft.Json.JsonTextReader.Read() at Newtonsoft.Json.Linq.JObject.Load(JsonReader reader, JsonLoadSettings settings) at Newtonsoft.Json.Linq.JObject.Parse(String json, JsonLoadSettings settings) at Newtonsoft.Json.Linq.JObject.Parse(String json) at ConsoleApp2.MQTTServer.<>c.b0_3(MqttApplicationMessageInterceptorContext c) in C:\Users\michaelr\source\repos\ConsoleApp2\ConsoleApp2\MQTTServer.cs:line 92 [2018-01-22T11:25:46.8968618-06:00] [16] [MqttRetainedMessagesManager] [Info]: Client 'testbed' set retained message for topic '/DWG/running'. 'testbed' reported '/DWG/running' > 'username8'>> [2018-01-22T11:25:46.8982075-06:00] [16] [MqttChannelAdapter] [Verbose]: TX >>> PubRec [Timeout=00:00:15] [2018-01-22T11:25:46.8992124-06:00] [16] [MqttChannelAdapter] [Verbose]: RX <<< PubRel [2018-01-22T11:25:46.8992124-06:00] [16] [MqttChannelAdapter] [Verbose]: TX >>> PubComp [Timeout=00:00:15] [2018-01-22T11:25:46.8992124-06:00] [16] [MqttChannelAdapter] [Verbose]: RX <<< Publish: [Topic=test] [Payload.Length=11] [QoSLevel=ExactlyOnce] [Dup=False] [Retain=True] [PacketIdentifier=10] Newtonsoft.Json.JsonReaderException: Unexpected character encountered while parsing value: j. Path '', line 0, position 0. at Newtonsoft.Json.JsonTextReader.ParseValue() at Newtonsoft.Json.JsonTextReader.Read() at Newtonsoft.Json.Linq.JObject.Load(JsonReader reader, JsonLoadSettings settings) at Newtonsoft.Json.Linq.JObject.Parse(String json, JsonLoadSettings settings) at Newtonsoft.Json.Linq.JObject.Parse(String json) at ConsoleApp2.MQTTServer.<>c.b__0_3(MqttApplicationMessageInterceptorContext c) in C:\Users\michaelr\source\repos\ConsoleApp2\ConsoleApp2\MQTTServer.cs:line 92 [2018-01-22T11:25:46.9162570-06:00] [16] [MqttRetainedMessagesManager] [Info]: Client 'testbed' set retained message for topic 'test'. 'testbed' reported 'test' > 'just a test'>> [2018-01-22T11:25:46.9172603-06:00] [16] [MqttChannelAdapter] [Verbose]: TX >>> PubRec [Timeout=00:00:15] [2018-01-22T11:25:46.9192659-06:00] [16] [MqttChannelAdapter] [Verbose]: RX <<< PubRel [2018-01-22T11:25:46.9192659-06:00] [16] [MqttChannelAdapter] [Verbose]: TX >>> PubComp [Timeout=00:00:15] [2018-01-22T11:25:46.9844401-06:00] [16] [MqttClientSession] [Warning]: Client 'testbed': Communication exception while processing client packets. MQTTnet.Exceptions.MqttCommunicationException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host at System.Net.Sockets.Socket.Receive(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags) at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size) --- End of inner exception stack trace --- at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size) at System.IO.BufferedStream.ReadByte() at MQTTnet.Serializer.MqttPacketReader.ReadHeaderFromSource(Stream stream, CancellationToken cancellationToken) at MQTTnet.Adapter.MqttChannelAdapter.d13.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at MQTTnet.Adapter.MqttChannelAdapter.<>c__DisplayClass12_0.<b0>d.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at MQTTnet.Adapter.MqttChannelAdapter.d14.MoveNext() --- End of inner exception stack trace --- at MQTTnet.Adapter.MqttChannelAdapter.d14.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at MQTTnet.Adapter.MqttChannelAdapter.d12.MoveNext() --- End of stack trace from previous location where exception was thrown --- at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task) at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task) at MQTTnet.Server.MqttClientSession.d__27.MoveNext() [2018-01-22T11:25:47.0214487-06:00] [17] [MqttChannelAdapter] [Verbose]: Disconnecting [Timeout=00:00:15] [2018-01-22T11:25:47.0234538-06:00] [17] [MqttClientSession] [Info]: Client 'testbed': Session stopped. [2018-01-22T11:25:47.0374907-06:00] [16] [MqttClientSession] [Verbose]: Client testbed: Stopped checking keep alive timeout. [2018-01-22T11:25:47.0374907-06:00] [16] [MqttClientSession] [Info]: Client 'testbed': Session stopped. [2018-01-22T11:25:47.0384928-06:00] [16] [MqttChannelAdapter] [Verbose]: Disconnecting [Timeout=00:00:15] [2018-01-22T11:25:47.0384928-06:00] [16] [MqttServer] [Info]: Client 'testbed': Disconnected. `

R3dNinja commented 6 years ago

As a followup, it looks like the server actually is passing along the last message. Just tested with the Clinet test app.

chkr1011 commented 6 years ago

Hi, please test again with the preview version of 2.7.0 (nuget). We fixed several connection relevant issues. Best regards Christian