From e0235aedff1614927491342ca5fee96f80bc3b02 Mon Sep 17 00:00:00 2001 From: Christian Kratky Date: Tue, 21 Nov 2017 20:55:57 +0100 Subject: [PATCH] Refactor trace messages --- Build/MQTTnet.nuspec | 10 +-- .../MqttChannelCommunicationAdapter.cs | 4 + MQTTnet.Core/Packets/MqttConnAckPacket.cs | 2 +- MQTTnet.Core/Packets/MqttConnectPacket.cs | 2 +- MQTTnet.Core/Packets/MqttDisconnectPacket.cs | 4 + MQTTnet.Core/Packets/MqttPingReqPacket.cs | 2 +- MQTTnet.Core/Packets/MqttPingRespPacket.cs | 2 +- MQTTnet.Core/Packets/MqttPubAckPacket.cs | 4 + MQTTnet.Core/Packets/MqttPubCompPacket.cs | 4 + MQTTnet.Core/Packets/MqttPubRecPacket.cs | 4 + MQTTnet.Core/Packets/MqttPubRelPacket.cs | 4 + MQTTnet.Core/Packets/MqttPublishPacket.cs | 5 +- MQTTnet.Core/Packets/MqttSubAckPacket.cs | 2 +- MQTTnet.Core/Packets/MqttSubscribePacket.cs | 2 +- MQTTnet.Core/Packets/MqttUnsubAckPacket.cs | 5 ++ MQTTnet.Core/Packets/MqttUnsubscribe.cs | 6 ++ .../MqttClientRetainedMessagesManager.cs | 77 ++++++++++--------- .../MainPage.xaml.cs | 30 ++++++-- 18 files changed, 111 insertions(+), 58 deletions(-) diff --git a/Build/MQTTnet.nuspec b/Build/MQTTnet.nuspec index cd218576..faccaefb 100644 --- a/Build/MQTTnet.nuspec +++ b/Build/MQTTnet.nuspec @@ -2,7 +2,7 @@ MQTTnet - 2.5.2-rc1 + 2.5.2 Christian Kratky Christian Kratky https://github.com/chkr1011/MQTTnet/blob/master/LICENSE @@ -10,13 +10,7 @@ https://raw.githubusercontent.com/chkr1011/MQTTnet/master/Images/Logo_128x128.png false MQTTnet is a high performance .NET library for MQTT based communication. It provides a MQTT client and a MQTT server (broker). - * [Core] Fixed library reference issues for .NET 4.6 and netstandard 2.0 (Thanks to @JanEggers). -* [Core] Several COM exceptions are now wrapped properly resulting in less warnings in the trace. -* [Core] Removed application message payload from trace to reduce trace size and increase performance. -* [Client] Fixed WebSocket sub protocol negotiation for ASP.NET Core 2 servers (Thanks to @JanEggers). -* [Client] Fixed broken connection after 30 seconds then using WebSocket protocol (Thanks to @ChristianRiedl). -* [Server] Client connections are now closed when the server is stopped (Thanks to @zhudanfei). -* [Server] Published messages from the server are now retained (if set) (Thanks to @ChristianRiedl). BREAKING CHANGE! + * [Core] Refactored trace messages. Copyright Christian Kratky 2016-2017 MQTT Message Queue Telemetry Transport MQTTClient MQTTServer Server MQTTBroker Broker NETStandard IoT InternetOfThings Messaging Hardware Arduino Sensor Actuator M2M ESP Smart Home Cities Automation Xamarin diff --git a/MQTTnet.Core/Adapter/MqttChannelCommunicationAdapter.cs b/MQTTnet.Core/Adapter/MqttChannelCommunicationAdapter.cs index c859ec0d..5b0038d1 100644 --- a/MQTTnet.Core/Adapter/MqttChannelCommunicationAdapter.cs +++ b/MQTTnet.Core/Adapter/MqttChannelCommunicationAdapter.cs @@ -32,11 +32,15 @@ namespace MQTTnet.Core.Adapter public async Task ConnectAsync(TimeSpan timeout) { + _logger.LogInformation("Connecting [Timeout={0}]", timeout); + await ExecuteAndWrapExceptionAsync(() => _channel.ConnectAsync().TimeoutAfter(timeout)); } public async Task DisconnectAsync(TimeSpan timeout) { + _logger.LogInformation("Disconnecting [Timeout={0}]", timeout); + await ExecuteAndWrapExceptionAsync(() => _channel.DisconnectAsync().TimeoutAfter(timeout)); } diff --git a/MQTTnet.Core/Packets/MqttConnAckPacket.cs b/MQTTnet.Core/Packets/MqttConnAckPacket.cs index e80a0af5..0410e669 100644 --- a/MQTTnet.Core/Packets/MqttConnAckPacket.cs +++ b/MQTTnet.Core/Packets/MqttConnAckPacket.cs @@ -10,7 +10,7 @@ namespace MQTTnet.Core.Packets public override string ToString() { - return nameof(MqttConnAckPacket) + ": [ConnectReturnCode=" + ConnectReturnCode + "] [IsSessionPresent=" + IsSessionPresent + "]"; + return "ConnAck: [ConnectReturnCode=" + ConnectReturnCode + "] [IsSessionPresent=" + IsSessionPresent + "]"; } } } diff --git a/MQTTnet.Core/Packets/MqttConnectPacket.cs b/MQTTnet.Core/Packets/MqttConnectPacket.cs index b1d6e3b9..48817120 100644 --- a/MQTTnet.Core/Packets/MqttConnectPacket.cs +++ b/MQTTnet.Core/Packets/MqttConnectPacket.cs @@ -20,7 +20,7 @@ namespace MQTTnet.Core.Packets public override string ToString() { - return nameof(MqttConnectPacket) + ": [ClientId=" + ClientId + "] [Username=" + Username + "] [Password=" + Password + "] [KeepAlivePeriod=" + KeepAlivePeriod + "] [CleanSession=" + CleanSession + "]"; + return "Connect: [ClientId=" + ClientId + "] [Username=" + Username + "] [Password=" + Password + "] [KeepAlivePeriod=" + KeepAlivePeriod + "] [CleanSession=" + CleanSession + "]"; } } } diff --git a/MQTTnet.Core/Packets/MqttDisconnectPacket.cs b/MQTTnet.Core/Packets/MqttDisconnectPacket.cs index 5be8407f..4db7f795 100644 --- a/MQTTnet.Core/Packets/MqttDisconnectPacket.cs +++ b/MQTTnet.Core/Packets/MqttDisconnectPacket.cs @@ -2,5 +2,9 @@ { public sealed class MqttDisconnectPacket : MqttBasePacket { + public override string ToString() + { + return "Disconnect"; + } } } diff --git a/MQTTnet.Core/Packets/MqttPingReqPacket.cs b/MQTTnet.Core/Packets/MqttPingReqPacket.cs index 3df1c3ae..9836b5aa 100644 --- a/MQTTnet.Core/Packets/MqttPingReqPacket.cs +++ b/MQTTnet.Core/Packets/MqttPingReqPacket.cs @@ -4,7 +4,7 @@ { public override string ToString() { - return nameof(MqttPingReqPacket); + return "PingReq"; } } } diff --git a/MQTTnet.Core/Packets/MqttPingRespPacket.cs b/MQTTnet.Core/Packets/MqttPingRespPacket.cs index 753a357d..eff12b83 100644 --- a/MQTTnet.Core/Packets/MqttPingRespPacket.cs +++ b/MQTTnet.Core/Packets/MqttPingRespPacket.cs @@ -4,7 +4,7 @@ { public override string ToString() { - return nameof(MqttPingRespPacket); + return "PingResp"; } } } diff --git a/MQTTnet.Core/Packets/MqttPubAckPacket.cs b/MQTTnet.Core/Packets/MqttPubAckPacket.cs index b3e5d3e3..9e07cd32 100644 --- a/MQTTnet.Core/Packets/MqttPubAckPacket.cs +++ b/MQTTnet.Core/Packets/MqttPubAckPacket.cs @@ -2,5 +2,9 @@ { public sealed class MqttPubAckPacket : MqttBasePublishPacket { + public override string ToString() + { + return "PubAck"; + } } } diff --git a/MQTTnet.Core/Packets/MqttPubCompPacket.cs b/MQTTnet.Core/Packets/MqttPubCompPacket.cs index cb6b485f..9b819fd0 100644 --- a/MQTTnet.Core/Packets/MqttPubCompPacket.cs +++ b/MQTTnet.Core/Packets/MqttPubCompPacket.cs @@ -2,5 +2,9 @@ { public sealed class MqttPubCompPacket : MqttBasePublishPacket { + public override string ToString() + { + return "PubComp"; + } } } diff --git a/MQTTnet.Core/Packets/MqttPubRecPacket.cs b/MQTTnet.Core/Packets/MqttPubRecPacket.cs index a8ed3337..3b876559 100644 --- a/MQTTnet.Core/Packets/MqttPubRecPacket.cs +++ b/MQTTnet.Core/Packets/MqttPubRecPacket.cs @@ -2,5 +2,9 @@ { public sealed class MqttPubRecPacket : MqttBasePublishPacket { + public override string ToString() + { + return "PubRec"; + } } } diff --git a/MQTTnet.Core/Packets/MqttPubRelPacket.cs b/MQTTnet.Core/Packets/MqttPubRelPacket.cs index c95d16bf..9d926894 100644 --- a/MQTTnet.Core/Packets/MqttPubRelPacket.cs +++ b/MQTTnet.Core/Packets/MqttPubRelPacket.cs @@ -2,5 +2,9 @@ { public sealed class MqttPubRelPacket : MqttBasePublishPacket { + public override string ToString() + { + return "PubRel"; + } } } diff --git a/MQTTnet.Core/Packets/MqttPublishPacket.cs b/MQTTnet.Core/Packets/MqttPublishPacket.cs index b7d10d11..573ff691 100644 --- a/MQTTnet.Core/Packets/MqttPublishPacket.cs +++ b/MQTTnet.Core/Packets/MqttPublishPacket.cs @@ -16,9 +16,8 @@ namespace MQTTnet.Core.Packets public override string ToString() { - return nameof(MqttPublishPacket) + - ": [Topic=" + Topic + "]" + - " [PayloadLength=" + Payload?.Length + "]" + + return "Publish: [Topic=" + Topic + "]" + + " [Payload.Length=" + Payload?.Length + "]" + " [QoSLevel=" + QualityOfServiceLevel + "]" + " [Dup=" + Dup + "]" + " [Retain=" + Retain + "]" + diff --git a/MQTTnet.Core/Packets/MqttSubAckPacket.cs b/MQTTnet.Core/Packets/MqttSubAckPacket.cs index 5882d4c8..05431a3f 100644 --- a/MQTTnet.Core/Packets/MqttSubAckPacket.cs +++ b/MQTTnet.Core/Packets/MqttSubAckPacket.cs @@ -13,7 +13,7 @@ namespace MQTTnet.Core.Packets public override string ToString() { var subscribeReturnCodesText = string.Join(",", SubscribeReturnCodes.Select(f => f.ToString())); - return nameof(MqttSubAckPacket) + ": [PacketIdentifier=" + PacketIdentifier + "] [SubscribeReturnCodes=" + subscribeReturnCodesText + "]"; + return "SubAck: [PacketIdentifier=" + PacketIdentifier + "] [SubscribeReturnCodes=" + subscribeReturnCodesText + "]"; } } } diff --git a/MQTTnet.Core/Packets/MqttSubscribePacket.cs b/MQTTnet.Core/Packets/MqttSubscribePacket.cs index 5cf1c260..c911efcc 100644 --- a/MQTTnet.Core/Packets/MqttSubscribePacket.cs +++ b/MQTTnet.Core/Packets/MqttSubscribePacket.cs @@ -12,7 +12,7 @@ namespace MQTTnet.Core.Packets public override string ToString() { var topicFiltersText = string.Join(",", TopicFilters.Select(f => f.Topic + "@" + f.QualityOfServiceLevel)); - return nameof(MqttSubscribePacket) + ": [PacketIdentifier=" + PacketIdentifier + "] [TopicFilters=" + topicFiltersText + "]"; + return "Subscribe: [PacketIdentifier=" + PacketIdentifier + "] [TopicFilters=" + topicFiltersText + "]"; } } } diff --git a/MQTTnet.Core/Packets/MqttUnsubAckPacket.cs b/MQTTnet.Core/Packets/MqttUnsubAckPacket.cs index 57a5a7dd..3554fa95 100644 --- a/MQTTnet.Core/Packets/MqttUnsubAckPacket.cs +++ b/MQTTnet.Core/Packets/MqttUnsubAckPacket.cs @@ -3,5 +3,10 @@ public sealed class MqttUnsubAckPacket : MqttBasePacket, IMqttPacketWithIdentifier { public ushort PacketIdentifier { get; set; } + + public override string ToString() + { + return "UnsubAck: [PacketIdentifier=" + PacketIdentifier + "]"; + } } } diff --git a/MQTTnet.Core/Packets/MqttUnsubscribe.cs b/MQTTnet.Core/Packets/MqttUnsubscribe.cs index 269bfcbb..1e06e50e 100644 --- a/MQTTnet.Core/Packets/MqttUnsubscribe.cs +++ b/MQTTnet.Core/Packets/MqttUnsubscribe.cs @@ -7,5 +7,11 @@ namespace MQTTnet.Core.Packets public ushort PacketIdentifier { get; set; } public IList TopicFilters { get; set; } = new List(); + + public override string ToString() + { + var topicFiltersText = string.Join(",", TopicFilters); + return "Subscribe: [PacketIdentifier=" + PacketIdentifier + "] [TopicFilters=" + topicFiltersText + "]"; + } } } diff --git a/MQTTnet.Core/Server/MqttClientRetainedMessagesManager.cs b/MQTTnet.Core/Server/MqttClientRetainedMessagesManager.cs index ab1d4871..5fe8522c 100644 --- a/MQTTnet.Core/Server/MqttClientRetainedMessagesManager.cs +++ b/MQTTnet.Core/Server/MqttClientRetainedMessagesManager.cs @@ -57,42 +57,7 @@ namespace MQTTnet.Core.Server await _gate.WaitAsync().ConfigureAwait(false); try { - var saveIsRequired = false; - - if (applicationMessage.Payload?.Any() == false) - { - saveIsRequired = _retainedMessages.Remove(applicationMessage.Topic); - _logger.LogInformation("Client '{0}' cleared retained message for topic '{1}'.", clientId, applicationMessage.Topic); - } - else - { - if (!_retainedMessages.ContainsKey(applicationMessage.Topic)) - { - _retainedMessages[applicationMessage.Topic] = applicationMessage; - saveIsRequired = true; - } - else - { - var existingMessage = _retainedMessages[applicationMessage.Topic]; - if (existingMessage.QualityOfServiceLevel != applicationMessage.QualityOfServiceLevel || !existingMessage.Payload.SequenceEqual(applicationMessage.Payload ?? new byte[0])) - { - _retainedMessages[applicationMessage.Topic] = applicationMessage; - saveIsRequired = true; - } - } - - _logger.LogInformation("Client '{0}' set retained message for topic '{1}'.", clientId, applicationMessage.Topic); - } - - if (!saveIsRequired) - { - _logger.LogTrace("Skipped saving retained messages because no changes were detected."); - } - - if (saveIsRequired && _options.Storage != null) - { - await _options.Storage.SaveRetainedMessagesAsync(_retainedMessages.Values.ToList()); - } + await HandleMessageInternalAsync(clientId, applicationMessage); } catch (Exception exception) { @@ -137,5 +102,45 @@ namespace MQTTnet.Core.Server return retainedMessages; } + + private async Task HandleMessageInternalAsync(string clientId, MqttApplicationMessage applicationMessage) + { + var saveIsRequired = false; + + if (applicationMessage.Payload?.Any() == false) + { + saveIsRequired = _retainedMessages.Remove(applicationMessage.Topic); + _logger.LogInformation("Client '{0}' cleared retained message for topic '{1}'.", clientId, applicationMessage.Topic); + } + else + { + if (!_retainedMessages.ContainsKey(applicationMessage.Topic)) + { + _retainedMessages[applicationMessage.Topic] = applicationMessage; + saveIsRequired = true; + } + else + { + var existingMessage = _retainedMessages[applicationMessage.Topic]; + if (existingMessage.QualityOfServiceLevel != applicationMessage.QualityOfServiceLevel || !existingMessage.Payload.SequenceEqual(applicationMessage.Payload ?? new byte[0])) + { + _retainedMessages[applicationMessage.Topic] = applicationMessage; + saveIsRequired = true; + } + } + + _logger.LogInformation("Client '{0}' set retained message for topic '{1}'.", clientId, applicationMessage.Topic); + } + + if (!saveIsRequired) + { + _logger.LogTrace("Skipped saving retained messages because no changes were detected."); + } + + if (saveIsRequired && _options.Storage != null) + { + await _options.Storage.SaveRetainedMessagesAsync(_retainedMessages.Values.ToList()); + } + } } } diff --git a/Tests/MQTTnet.TestApp.UniversalWindows/MainPage.xaml.cs b/Tests/MQTTnet.TestApp.UniversalWindows/MainPage.xaml.cs index 5e1a1261..fcf6d091 100644 --- a/Tests/MQTTnet.TestApp.UniversalWindows/MainPage.xaml.cs +++ b/Tests/MQTTnet.TestApp.UniversalWindows/MainPage.xaml.cs @@ -1,4 +1,5 @@ using System; +using System.Collections.Concurrent; using System.Text; using System.Threading.Tasks; using Windows.Security.Cryptography.Certificates; @@ -18,6 +19,8 @@ namespace MQTTnet.TestApp.UniversalWindows { public sealed partial class MainPage { + private readonly ConcurrentQueue _traceMessages = new ConcurrentQueue(); + private IMqttClient _mqttClient; private IMqttServer _mqttServer; @@ -30,15 +33,32 @@ namespace MQTTnet.TestApp.UniversalWindows private async void OnTraceMessagePublished(object sender, MqttNetTraceMessagePublishedEventArgs e) { - var text = $"[{e.TraceMessage.Timestamp:yyyy-MM-dd HH:mm:ss.fff}] [{e.TraceMessage.Level}] [{e.TraceMessage.Source}] [{e.TraceMessage.ThreadId}] [{e.TraceMessage.Message}]{Environment.NewLine}"; - if (e.TraceMessage.Exception != null) + _traceMessages.Enqueue(e.TraceMessage); + while (_traceMessages.Count > 100) { - text += $"{e.TraceMessage.Exception}{Environment.NewLine}"; + _traceMessages.TryDequeue(out _); } - + + var logText = new StringBuilder(); + foreach (var traceMessage in _traceMessages) + { + logText.AppendFormat( + "[{0:yyyy-MM-dd HH:mm:ss.fff}] [{1}] [{2}] [{3}] [{4}]{5}", traceMessage.Timestamp, + traceMessage.Level, + traceMessage.Source, + traceMessage.ThreadId, + traceMessage.Message, + Environment.NewLine); + + if (traceMessage.Exception != null) + { + logText.AppendLine(traceMessage.Exception.ToString()); + } + } + await Trace.Dispatcher.RunAsync(CoreDispatcherPriority.Low, () => { - Trace.Text += text; + Trace.Text = logText.ToString(); }); }