NLog: Better logging with configuration examples (#94)

README.md

@@ -151,6 +151,42 @@ For more examples that you can easily copy/paste, see our [Examples](https://git
 
 There is even an https://github.com/hivemq/hivemq-mqtt-client-dotnet/tree/main/Examples/HiveMQtt-CLI to demonstrate usage of the package.
 
+## Configuration
+
+### Logging
+
+The HiveMQtt package uses [NLog](https://github.com/NLog/NLog) and can be configured with a configuration file (`NLog.config`).  Having this file in the same directory of your executable will configure the HiveMQtt logger to output as configured:
+
+```xml
+<?xml version="1.0" encoding="utf-8" ?>
+<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
+      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
+
+  <targets>
+    <target name="logfile" xsi:type="File" fileName="HiveMQtt.log" />
+    <target name="logconsole" xsi:type="Console" />
+  </targets>
+
+  <rules>
+     <!-- minlevel can be Debug, Info, Warn, Error and Fatal or Trace -->
+    <logger name="HiveMQtt.*" minlevel="Error" writeTo="logconsole" />
+  </rules>
+</nlog>
+
+```
+
+Setting `minlevel` to `Trace` will output all activity in the HiveMQtt package down to packet and event handling.  Using this level will produce a lot of output such as the following:
+
+```log
+2023-10-04 16:56:54.9373|TRACE|HiveMQtt.Client.HiveMQClient|BeforeConnectEventLauncher
+2023-10-04 16:56:55.0081|TRACE|HiveMQtt.Client.HiveMQClient|7: TrafficInflowProcessor Starting...Connecting
+2023-10-04 16:56:55.0081|TRACE|HiveMQtt.Client.HiveMQClient|9: TrafficOutflowProcessor Starting...Connecting
+2023-10-04 16:56:55.0081|TRACE|HiveMQtt.Client.HiveMQClient|--> ConnectPacket
+2023-10-04 16:56:55.0128|TRACE|HiveMQtt.Client.HiveMQClient|OnConnectSentEventLauncher
+2023-10-04 16:56:55.0374|TRACE|HiveMQtt.Client.HiveMQClient|<-- ConnAck
+2023-10-04 16:56:55.0374|TRACE|HiveMQtt.Client.HiveMQClient|OnConnAckReceivedEventLauncher
+2023-10-04 16:56:55.0379|TRACE|HiveMQtt.Client.HiveMQClient|AfterConnectEventLauncher
+```
 
 ## Other MQTT Clients
 

Source/HiveMQtt/Client/Events/BeforeDisconnectEventArgs.cs

@@ -15,18 +15,14 @@
  */
 namespace HiveMQtt.Client.Events;
 
-using HiveMQtt.Client.Options;
-
 /// <summary>
 /// Event arguments for the <see cref="HiveMQClient.BeforeDisconnect"/> event.
 /// <para>This event is called before a disconnect is sent to the broker.</para>
-/// <para><see cref="BeforeDisconnectEventArgs.Options"/> contains the options of the disconnect operation.</para>
 /// </summary>
 public class BeforeDisconnectEventArgs : EventArgs
 {
     public BeforeDisconnectEventArgs()
     {
     }
 
-    public HiveMQClientOptions Options { get; set; }
 }

Source/HiveMQtt/Client/HiveMQClient.cs

@@ -34,6 +34,8 @@ namespace HiveMQtt.Client;
 /// </summary>
 public partial class HiveMQClient : IDisposable, IHiveMQClient
 {
+    private static readonly NLog.Logger Logger = NLog.LogManager.GetCurrentClassLogger();
+
     private ConnectState connectState = ConnectState.Disconnected;
 
     public HiveMQClient(HiveMQClientOptions? options = null)
@@ -84,10 +86,10 @@ public async Task<ConnectResult> ConnectAsync()
         {
             connAck = await taskCompletionSource.Task.WaitAsync(TimeSpan.FromSeconds(5)).ConfigureAwait(false);
         }
-        catch (System.TimeoutException)
+        catch (TimeoutException)
         {
-            // log.Error(string.Format("Connect timeout.  No response received in time.", ex);
-            throw;
+            this.connectState = ConnectState.Disconnected;
+            throw new HiveMQttClientException("Connect timeout.  No response received in time.");
         }
         finally
         {
@@ -148,7 +150,7 @@ public async Task<bool> DisconnectAsync(DisconnectOptions? options = null)
         {
             disconnectPacket = await taskCompletionSource.Task.WaitAsync(TimeSpan.FromSeconds(5)).ConfigureAwait(false);
         }
-        catch (System.TimeoutException)
+        catch (TimeoutException)
         {
             // Does it matter?  We're disconnecting anyway.
         }
@@ -161,6 +163,9 @@ public async Task<bool> DisconnectAsync(DisconnectOptions? options = null)
         // Close the socket
         this.CloseSocket();
 
+        // Fire the corresponding event
+        this.AfterDisconnectEventLauncher(true);
+
         this.connectState = ConnectState.Disconnected;
 
         // Clear the send queue
@@ -284,7 +289,7 @@ public async Task<SubscribeResult> SubscribeAsync(SubscribeOptions options)
 
             // FIXME: Validate that the packet identifier matches
         }
-        catch (System.TimeoutException ex)
+        catch (TimeoutException ex)
         {
             // log.Error(string.Format("Connect timeout.  No response received in time.", ex);
             throw ex;
@@ -358,7 +363,7 @@ public async Task<UnsubscribeResult> UnsubscribeAsync(List<Subscription> subscri
 
             // FIXME: Validate that the packet identifier matches
         }
-        catch (System.TimeoutException)
+        catch (TimeoutException)
         {
             // log.Error(string.Format("Connect timeout.  No response received in time.", ex);
             throw;

Source/HiveMQtt/Client/HiveMQClientEvents.cs

@@ -17,7 +17,6 @@ namespace HiveMQtt.Client;
 
 using System;
 using System.Diagnostics;
-using System.Security.Claims;
 using HiveMQtt.Client.Events;
 using HiveMQtt.Client.Options;
 using HiveMQtt.Client.Results;
@@ -39,7 +38,7 @@ public partial class HiveMQClient : IDisposable, IHiveMQClient
     protected virtual void BeforeConnectEventLauncher(HiveMQClientOptions options)
     {
         var eventArgs = new BeforeConnectEventArgs(options);
-        Trace.WriteLine("BeforeConnectEventLauncher");
+        Logger.Trace("BeforeConnectEventLauncher");
         this.BeforeConnect?.Invoke(this, eventArgs);
     }
 
@@ -51,7 +50,7 @@ protected virtual void BeforeConnectEventLauncher(HiveMQClientOptions options)
     protected virtual void AfterConnectEventLauncher(ConnectResult results)
     {
         var eventArgs = new AfterConnectEventArgs(results);
-        Trace.WriteLine("AfterConnectEventLauncher");
+        Logger.Trace("AfterConnectEventLauncher");
         this.AfterConnect?.Invoke(this, eventArgs);
     }
 
@@ -63,7 +62,7 @@ protected virtual void AfterConnectEventLauncher(ConnectResult results)
     protected virtual void BeforeDisconnectEventLauncher()
     {
         var eventArgs = new BeforeDisconnectEventArgs();
-        Trace.WriteLine("BeforeDisconnectEventLauncher");
+        Logger.Trace("BeforeDisconnectEventLauncher");
         this.BeforeDisconnect?.Invoke(this, eventArgs);
     }
 
@@ -75,7 +74,7 @@ protected virtual void BeforeDisconnectEventLauncher()
     protected virtual void AfterDisconnectEventLauncher(bool clean = false)
     {
         var eventArgs = new AfterDisconnectEventArgs(clean);
-        Trace.WriteLine("AfterDisconnectEventLauncher");
+        Logger.Trace("AfterDisconnectEventLauncher");
         this.AfterDisconnect?.Invoke(this, eventArgs);
     }
 
@@ -87,7 +86,7 @@ protected virtual void AfterDisconnectEventLauncher(bool clean = false)
     protected virtual void BeforeSubscribeEventLauncher(SubscribeOptions options)
     {
         var eventArgs = new BeforeSubscribeEventArgs(options);
-        Trace.WriteLine("BeforeSubscribeEventLauncher");
+        Logger.Trace("BeforeSubscribeEventLauncher");
         this.BeforeSubscribe?.Invoke(this, eventArgs);
     }
 
@@ -99,7 +98,7 @@ protected virtual void BeforeSubscribeEventLauncher(SubscribeOptions options)
     protected virtual void AfterSubscribeEventLauncher(SubscribeResult results)
     {
         var eventArgs = new AfterSubscribeEventArgs(results);
-        Trace.WriteLine("AfterSubscribeEventLauncher");
+        Logger.Trace("AfterSubscribeEventLauncher");
         this.AfterSubscribe?.Invoke(this, eventArgs);
     }
 
@@ -111,7 +110,7 @@ protected virtual void AfterSubscribeEventLauncher(SubscribeResult results)
     protected virtual void BeforeUnsubscribeEventLauncher(List<Subscription> subscriptions)
     {
         var eventArgs = new BeforeUnsubscribeEventArgs(subscriptions);
-        Trace.WriteLine("BeforeUnsubscribeEventLauncher");
+        Logger.Trace("BeforeUnsubscribeEventLauncher");
         this.BeforeUnsubscribe?.Invoke(this, eventArgs);
     }
 
@@ -123,7 +122,7 @@ protected virtual void BeforeUnsubscribeEventLauncher(List<Subscription> subscri
     protected virtual void AfterUnsubscribeEventLauncher(UnsubscribeResult results)
     {
         var eventArgs = new AfterUnsubscribeEventArgs(results);
-        Trace.WriteLine("AfterUnsubscribeEventLauncher");
+        Logger.Trace("AfterUnsubscribeEventLauncher");
         this.AfterUnsubscribe?.Invoke(this, eventArgs);
     }
 
@@ -135,7 +134,7 @@ protected virtual void AfterUnsubscribeEventLauncher(UnsubscribeResult results)
     protected virtual void OnMessageReceivedEventLauncher(PublishPacket packet)
     {
         var eventArgs = new OnMessageReceivedEventArgs(packet.Message);
-        Trace.WriteLine("OnMessageReceivedEventLauncher");
+        Logger.Trace("OnMessageReceivedEventLauncher");
         this.OnMessageReceived?.Invoke(this, eventArgs);
     }
 
@@ -151,7 +150,7 @@ protected virtual void OnMessageReceivedEventLauncher(PublishPacket packet)
     protected virtual void OnConnectSentEventLauncher(ConnectPacket packet)
     {
         var eventArgs = new OnConnectSentEventArgs(packet);
-        Trace.WriteLine("OnConnectSentEventLauncher");
+        Logger.Trace("OnConnectSentEventLauncher");
         this.OnConnectSent?.Invoke(this, eventArgs);
     }
 
@@ -163,7 +162,7 @@ protected virtual void OnConnectSentEventLauncher(ConnectPacket packet)
     protected virtual void OnConnAckReceivedEventLauncher(ConnAckPacket packet)
     {
         var eventArgs = new OnConnAckReceivedEventArgs(packet);
-        Trace.WriteLine("OnConnAckReceivedEventLauncher");
+        Logger.Trace("OnConnAckReceivedEventLauncher");
         this.OnConnAckReceived?.Invoke(this, eventArgs);
     }
 
@@ -175,7 +174,7 @@ protected virtual void OnConnAckReceivedEventLauncher(ConnAckPacket packet)
     protected virtual void OnDisconnectSentEventLauncher(DisconnectPacket packet)
     {
         var eventArgs = new OnDisconnectSentEventArgs(packet);
-        Trace.WriteLine("OnDisconnectSentEventLauncher");
+        Logger.Trace("OnDisconnectSentEventLauncher");
         this.OnDisconnectSent?.Invoke(this, eventArgs);
     }
 
@@ -187,7 +186,7 @@ protected virtual void OnDisconnectSentEventLauncher(DisconnectPacket packet)
     protected virtual void OnDisconnectReceivedEventLauncher(DisconnectPacket packet)
     {
         var eventArgs = new OnDisconnectReceivedEventArgs(packet);
-        Trace.WriteLine("OnDisconnectReceivedEventLauncher: ReasonCode: " + packet.DisconnectReasonCode + " ReasonString: " + packet.Properties.ReasonString);
+        Logger.Trace("OnDisconnectReceivedEventLauncher: ReasonCode: " + packet.DisconnectReasonCode + " ReasonString: " + packet.Properties.ReasonString);
         this.OnDisconnectReceived?.Invoke(this, eventArgs);
     }
 
@@ -199,7 +198,7 @@ protected virtual void OnDisconnectReceivedEventLauncher(DisconnectPacket packet
     protected virtual void OnPingReqSentEventLauncher(PingReqPacket packet)
     {
         var eventArgs = new OnPingReqSentEventArgs(packet);
-        Trace.WriteLine("OnPingReqSentEventLauncher");
+        Logger.Trace("OnPingReqSentEventLauncher");
         this.OnPingReqSent?.Invoke(this, eventArgs);
     }
 
@@ -211,7 +210,7 @@ protected virtual void OnPingReqSentEventLauncher(PingReqPacket packet)
     protected virtual void OnPingRespReceivedEventLauncher(PingRespPacket packet)
     {
         var eventArgs = new OnPingRespReceivedEventArgs(packet);
-        Trace.WriteLine("OnPingRespReceivedEventLauncher");
+        Logger.Trace("OnPingRespReceivedEventLauncher");
         this.OnPingRespReceived?.Invoke(this, eventArgs);
     }
 
@@ -223,7 +222,7 @@ protected virtual void OnPingRespReceivedEventLauncher(PingRespPacket packet)
     protected virtual void OnSubscribeSentEventLauncher(SubscribePacket packet)
     {
         var eventArgs = new OnSubscribeSentEventArgs(packet);
-        Trace.WriteLine("OnSubscribeSentEventLauncher");
+        Logger.Trace("OnSubscribeSentEventLauncher");
         this.OnSubscribeSent?.Invoke(this, eventArgs);
     }
 
@@ -235,7 +234,7 @@ protected virtual void OnSubscribeSentEventLauncher(SubscribePacket packet)
     protected virtual void OnSubAckReceivedEventLauncher(SubAckPacket packet)
     {
         var eventArgs = new OnSubAckReceivedEventArgs(packet);
-        Trace.WriteLine("OnSubAckReceivedEventLauncher");
+        Logger.Trace("OnSubAckReceivedEventLauncher");
         this.OnSubAckReceived?.Invoke(this, eventArgs);
     }
 
@@ -247,7 +246,7 @@ protected virtual void OnSubAckReceivedEventLauncher(SubAckPacket packet)
     protected virtual void OnUnsubscribeSentEventLauncher(UnsubscribePacket packet)
     {
         var eventArgs = new OnUnsubscribeSentEventArgs(packet);
-        Trace.WriteLine("OnUnsubscribeSentEventLauncher");
+        Logger.Trace("OnUnsubscribeSentEventLauncher");
         this.OnUnsubscribeSent?.Invoke(this, eventArgs);
     }
 
@@ -259,7 +258,7 @@ protected virtual void OnUnsubscribeSentEventLauncher(UnsubscribePacket packet)
     protected virtual void OnUnsubAckReceivedEventLauncher(UnsubAckPacket packet)
     {
         var eventArgs = new OnUnsubAckReceivedEventArgs(packet);
-        Trace.WriteLine("OnUnsubAckReceivedEventLauncher");
+        Logger.Trace("OnUnsubAckReceivedEventLauncher");
         this.OnUnsubAckReceived?.Invoke(this, eventArgs);
     }
 
@@ -271,7 +270,7 @@ protected virtual void OnUnsubAckReceivedEventLauncher(UnsubAckPacket packet)
     protected virtual void OnPublishReceivedEventLauncher(PublishPacket packet)
     {
         var eventArgs = new OnPublishReceivedEventArgs(packet);
-        Trace.WriteLine("OnPublishReceivedEventLauncher");
+        Logger.Trace("OnPublishReceivedEventLauncher");
         this.OnPublishReceived?.Invoke(this, eventArgs);
     }
 
@@ -283,7 +282,7 @@ protected virtual void OnPublishReceivedEventLauncher(PublishPacket packet)
     protected virtual void OnPublishSentEventLauncher(PublishPacket packet)
     {
         var eventArgs = new OnPublishSentEventArgs(packet);
-        Trace.WriteLine("OnPublishSentEventLauncher");
+        Logger.Trace("OnPublishSentEventLauncher");
         this.OnPublishSent?.Invoke(this, eventArgs);
     }
 
@@ -295,7 +294,7 @@ protected virtual void OnPublishSentEventLauncher(PublishPacket packet)
     protected virtual void OnPubAckReceivedEventLauncher(PubAckPacket packet)
     {
         var eventArgs = new OnPubAckReceivedEventArgs(packet);
-        Trace.WriteLine("OnPubAckReceivedEventLauncher");
+        Logger.Trace("OnPubAckReceivedEventLauncher");
         this.OnPubAckReceived?.Invoke(this, eventArgs);
     }
 
@@ -307,7 +306,7 @@ protected virtual void OnPubAckReceivedEventLauncher(PubAckPacket packet)
     protected virtual void OnPubAckSentEventLauncher(PubAckPacket packet)
     {
         var eventArgs = new OnPubAckSentEventArgs(packet);
-        Trace.WriteLine("OnPubAckSentEventLauncher");
+        Logger.Trace("OnPubAckSentEventLauncher");
         this.OnPubAckSent?.Invoke(this, eventArgs);
     }
 
@@ -319,7 +318,7 @@ protected virtual void OnPubAckSentEventLauncher(PubAckPacket packet)
     protected virtual void OnPubRecReceivedEventLauncher(PubRecPacket packet)
     {
         var eventArgs = new OnPubRecReceivedEventArgs(packet);
-        Trace.WriteLine("OnPubRecReceivedEventLauncher");
+        Logger.Trace("OnPubRecReceivedEventLauncher");
         this.OnPubRecReceived?.Invoke(this, eventArgs);
     }
 
@@ -331,7 +330,7 @@ protected virtual void OnPubRecReceivedEventLauncher(PubRecPacket packet)
     protected virtual void OnPubRecSentEventLauncher(PubRecPacket packet)
     {
         var eventArgs = new OnPubRecSentEventArgs(packet);
-        Trace.WriteLine("OnPubRecSentEventLauncher");
+        Logger.Trace("OnPubRecSentEventLauncher");
         this.OnPubRecSent?.Invoke(this, eventArgs);
     }
 
@@ -343,7 +342,7 @@ protected virtual void OnPubRecSentEventLauncher(PubRecPacket packet)
     protected virtual void OnPubRelReceivedEventLauncher(PubRelPacket packet)
     {
         var eventArgs = new OnPubRelReceivedEventArgs(packet);
-        Trace.WriteLine("OnPubRelReceivedEventLauncher");
+        Logger.Trace("OnPubRelReceivedEventLauncher");
         this.OnPubRelReceived?.Invoke(this, eventArgs);
     }
 
@@ -355,7 +354,7 @@ protected virtual void OnPubRelReceivedEventLauncher(PubRelPacket packet)
     protected virtual void OnPubRelSentEventLauncher(PubRelPacket packet)
     {
         var eventArgs = new OnPubRelSentEventArgs(packet);
-        Trace.WriteLine("OnPubRelSentEventLauncher");
+        Logger.Trace("OnPubRelSentEventLauncher");
         this.OnPubRelSent?.Invoke(this, eventArgs);
     }
 
@@ -367,7 +366,7 @@ protected virtual void OnPubRelSentEventLauncher(PubRelPacket packet)
     protected virtual void OnPubCompReceivedEventLauncher(PubCompPacket packet)
     {
         var eventArgs = new OnPubCompReceivedEventArgs(packet);
-        Trace.WriteLine("PubCompReceivedEventLauncher");
+        Logger.Trace("PubCompReceivedEventLauncher");
         this.OnPubCompReceived?.Invoke(this, eventArgs);
     }
 
@@ -379,7 +378,7 @@ protected virtual void OnPubCompReceivedEventLauncher(PubCompPacket packet)
     protected virtual void OnPubCompSentEventLauncher(PubCompPacket packet)
     {
         var eventArgs = new OnPubCompSentEventArgs(packet);
-        Trace.WriteLine("PubCompSentEventLauncher");
+        Logger.Trace("PubCompSentEventLauncher");
         this.OnPubCompSent?.Invoke(this, eventArgs);
     }
 }