Skip to content

Commit

Permalink
Add an event listener to log SDK events. (#7320)
Browse files Browse the repository at this point in the history
- This PR adds an event listener to log SDK events. The event listener is guarded by the env var and otherwise should have no effect.
- Also this PR fixes the devguide to specify .net 8.

Local testing is in progress...

## Azure IoT Edge PR checklist:
  • Loading branch information
vadim-kovalyov authored Sep 5, 2024
1 parent a8d0494 commit 3557a22
Show file tree
Hide file tree
Showing 6 changed files with 221 additions and 3 deletions.
2 changes: 2 additions & 0 deletions doc/EnvironmentVariables.md
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ You can set Edge Agent and Edge Hub environment variables in the Azure portal. I
| DisableDeviceAnalyticsMetadata | Whether to disable sending [basic metadata](https://github.com/Azure/azure-iotedge/blob/main/README.md#telemetry) about the device to Microsoft. | bool | false |
| EnableK8sServiceCallTracing | Whether to enable logging for K8s requests that the Agent makes | bool | false |
| EnableOrphanedIdentityCleanup | Whether to enable removal of any orphaned identities<br>NOTE: There is an issue with the `managedBy` tag for module identities that **WILL** cause this logic to remove **Host-Level** modules (i.e. managed by something other than `IotEdge`)</br> | bool | false |
| EnableSdkDebugLogs | If set, emits SDK client events to logs. Note that this method will substantially slow down execution. | bool | false |
| Https_Proxy | Address of the proxy to use for outbound HTTPS requests | string | |
| IntensiveCareTimeInMinutes | Time span for a module to be running before considered completely healthy (restart time / count cleared) | int32 | |
| K8sNamespace | K8s namespace to use for deploying modules | string | |
Expand Down Expand Up @@ -66,6 +67,7 @@ You can set Edge Agent and Edge Hub environment variables in the Azure portal. I
| ConnectivityCheckFrequencySecs | Interval at which EdgeHub will ping upstream to ensure connectivity is still present | int32 | 300 |
| DeviceScopeCacheRefreshRateSecs | Interval at which leaf and module identities are refreshed from upstream | int32 | 3600 |
| EnableRoutingLogging | Whether message routing logs should be enabled | bool | false |
| EnableSdkDebugLogs | If set, emits SDK client events to logs. Note that this method will substantially slow down execution. | bool | false |
| EncryptTwinStore | Whether to encrypt the twin data before persisting to disk | bool | true |
| Https_Proxy | Address of the proxy to use for outbound HTTPS requests | string | |
| HttpSettings__Enabled | Whether the HTTP server should be enabled | bool | true |
Expand Down
2 changes: 1 addition & 1 deletion doc/devguide.md
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ Make sure the following dependencies are installed in your environment before yo

| Dependency | Notes |
| ------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------- |
| .NET 6.0 | Installation instructions [here](https://www.microsoft.com/net/core). |
| .NET 8.0 | Installation instructions [here](https://www.microsoft.com/net/core). |
| Java | Not needed if building in VS IDE (Windows). Otherwise, a JRE is required to compile the Antlr4 grammar files into C# classes, and `java` must be on your path. |

## Build
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,95 @@
// Copyright (c) Microsoft. All rights reserved.
//----------------------
// <auto-generated>
// Used to trick stylecop into not processing this file
// </auto-generated>
//----------------------
// Licensed under the MIT license. See LICENSE file in the project root for full license information.

using Microsoft.Extensions.Logging;
using System;
using System.Diagnostics.Tracing;
using System.Globalization;
using System.Linq;

namespace Microsoft.Azure.Devices.Logging
{
/// <summary>
/// Prints SDK events to Console output - the log level is set to TRACE
/// NOTE: keep in sync with edge-hub/src/Microsoft.Azure.Devices.Edge.Hub.Core/ConsoleEventListener.cs
/// </summary>
public sealed class ConsoleEventListener : EventListener
{
private readonly string[] _eventFilters;
private readonly ILogger _logger;
private readonly object _lock = new object();

public ConsoleEventListener(string filter, ILogger logger)
{
_eventFilters = new string[1];
_eventFilters[0] = filter ?? throw new ArgumentNullException(nameof(filter));
_logger = logger;

InitializeEventSources();
}

public ConsoleEventListener(string[] filters, ILogger logger)
{
_eventFilters = filters ?? throw new ArgumentNullException(nameof(filters));
if (_eventFilters.Length == 0) throw new ArgumentException("Filters cannot be empty", nameof(filters));

foreach (string filter in _eventFilters)
{
if (string.IsNullOrWhiteSpace(filter))
{
throw new ArgumentNullException(nameof(filters));
}
}
_logger = logger;

InitializeEventSources();
}

private void InitializeEventSources()
{
foreach (EventSource source in EventSource.GetSources())
{
EnableEvents(source, EventLevel.LogAlways);
}
}

protected override void OnEventSourceCreated(EventSource eventSource)
{
base.OnEventSourceCreated(eventSource);
EnableEvents(
eventSource,
EventLevel.LogAlways
#if !NET451
, EventKeywords.All
#endif
);
}

protected override void OnEventWritten(EventWrittenEventArgs eventData)
{
if (_eventFilters == null) return;

lock (_lock)
{
if (_eventFilters.Any(ef => eventData.EventSource.Name.StartsWith(ef, StringComparison.Ordinal)))
{
string eventIdent;
#if NET451
// net451 doesn't have EventName, so we'll settle for EventId
eventIdent = eventData.EventId.ToString(CultureInfo.InvariantCulture);
#else
eventIdent = eventData.EventName;
#endif
string text = $"{DateTime.Now.ToString("yyyy-MM-ddTHH:mm:ss.fffffff", CultureInfo.InvariantCulture)} [SDK] [{eventData.EventSource.Name}-{eventIdent}]{(eventData.Payload != null ? $" ({string.Join(", ", eventData.Payload)})." : "")}";
_logger.LogInformation(text);
}
}
}
}
}

Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ namespace Microsoft.Azure.Devices.Edge.Agent.Service
using System;
using System.Collections;
using System.Collections.Generic;
using System.Diagnostics.Tracing;
using System.IO;
using System.Linq;
using System.Net;
Expand All @@ -21,6 +22,7 @@ namespace Microsoft.Azure.Devices.Edge.Agent.Service
using Microsoft.Azure.Devices.Edge.Storage;
using Microsoft.Azure.Devices.Edge.Util;
using Microsoft.Azure.Devices.Edge.Util.Metrics;
using Microsoft.Azure.Devices.Logging;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Logging;
using Constants = Microsoft.Azure.Devices.Edge.Agent.Core.Constants;
Expand Down Expand Up @@ -51,7 +53,18 @@ public static int Main()
// Bring up the logger before anything else so we can log errors ASAP
logger = SetupLogger(configuration);

return MainAsync(configuration, logger).Result;
if (configuration.GetValue<bool>("EnableSdkDebugLogs", false))
{
// Enable SDK debug logs, see ConsoleEventListener for details.
string[] eventFilter = new string[] { "DotNetty-Default", "Microsoft-Azure-Devices", "Azure-Core", "Azure-Identity" };
using var sdk = new ConsoleEventListener(eventFilter, logger);

return MainAsync(configuration, logger).Result;
}
else
{
return MainAsync(configuration, logger).Result;
}
}
catch (Exception ex)
{
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,95 @@
// Copyright (c) Microsoft. All rights reserved.
//----------------------
// <auto-generated>
// Used to trick stylecop into not processing this file
// </auto-generated>
//----------------------
// Licensed under the MIT license. See LICENSE file in the project root for full license information.

using Microsoft.Extensions.Logging;
using System;
using System.Diagnostics.Tracing;
using System.Globalization;
using System.Linq;

namespace Microsoft.Azure.Devices.Logging
{
/// <summary>
/// Prints SDK events to Console output - the log level is set to TRACE
/// NOTE: Keep in sync with edge-agent/src/Microsoft.Azure.Devices.Edge.Agent.Core/ConsoleEventListener.cs
/// </summary>
public sealed class ConsoleEventListener : EventListener
{
private readonly string[] _eventFilters;
private readonly ILogger _logger;
private readonly object _lock = new object();

public ConsoleEventListener(string filter, ILogger logger)
{
_eventFilters = new string[1];
_eventFilters[0] = filter ?? throw new ArgumentNullException(nameof(filter));
_logger = logger;

InitializeEventSources();
}

public ConsoleEventListener(string[] filters, ILogger logger)
{
_eventFilters = filters ?? throw new ArgumentNullException(nameof(filters));
if (_eventFilters.Length == 0) throw new ArgumentException("Filters cannot be empty", nameof(filters));

foreach (string filter in _eventFilters)
{
if (string.IsNullOrWhiteSpace(filter))
{
throw new ArgumentNullException(nameof(filters));
}
}
_logger = logger;

InitializeEventSources();
}

private void InitializeEventSources()
{
foreach (EventSource source in EventSource.GetSources())
{
EnableEvents(source, EventLevel.LogAlways);
}
}

protected override void OnEventSourceCreated(EventSource eventSource)
{
base.OnEventSourceCreated(eventSource);
EnableEvents(
eventSource,
EventLevel.LogAlways
#if !NET451
, EventKeywords.All
#endif
);
}

protected override void OnEventWritten(EventWrittenEventArgs eventData)
{
if (_eventFilters == null) return;

lock (_lock)
{
if (_eventFilters.Any(ef => eventData.EventSource.Name.StartsWith(ef, StringComparison.Ordinal)))
{
string eventIdent;
#if NET451
// net451 doesn't have EventName, so we'll settle for EventId
eventIdent = eventData.EventId.ToString(CultureInfo.InvariantCulture);
#else
eventIdent = eventData.EventName;
#endif
string text = $"{DateTime.Now.ToString("yyyy-MM-ddTHH:mm:ss.fffffff", CultureInfo.InvariantCulture)} [SDK] [{eventData.EventSource.Name}-{eventIdent}]{(eventData.Payload != null ? $" ({string.Join(", ", eventData.Payload)})." : "")}";
_logger.LogInformation(text);
}
}
}
}
}

Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ namespace Microsoft.Azure.Devices.Edge.Hub.Service
{
using System;
using System.Collections.Generic;
using System.Diagnostics.Tracing;
using System.Linq;
using System.Security.Authentication;
using System.Threading;
Expand All @@ -20,6 +21,7 @@ namespace Microsoft.Azure.Devices.Edge.Hub.Service
using Microsoft.Azure.Devices.Edge.Storage;
using Microsoft.Azure.Devices.Edge.Util;
using Microsoft.Azure.Devices.Edge.Util.Metrics;
using Microsoft.Azure.Devices.Logging;
using Microsoft.Azure.Devices.Routing.Core;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Logging;
Expand Down Expand Up @@ -52,7 +54,18 @@ public static int Main()

logger = Logger.Factory.CreateLogger("EdgeHub");

return MainAsync(configuration, logger).Result;
if (configuration.GetValue<bool>("EnableSdkDebugLogs", false))
{
// Enable SDK debug logs, see ConsoleEventListener for details
string[] eventFilter = new string[] { "DotNetty-Default", "Microsoft-Azure-Devices", "Azure-Core", "Azure-Identity" };
using var sdk = new ConsoleEventListener(eventFilter, logger);

return MainAsync(configuration, logger).Result;
}
else
{
return MainAsync(configuration, logger).Result;
}
}
catch (Exception ex)
{
Expand Down

0 comments on commit 3557a22

Please sign in to comment.