adding more properties to Azure Monitor logs (#6679)

brettsam · web-flow · commit 6479d9f1adef · 2020-09-30T13:07:08.000-07:00
diff --git a/src/WebJobs.Script.WebHost/Diagnostics/AzureMonitorDiagnosticLogger.cs b/src/WebJobs.Script.WebHost/Diagnostics/AzureMonitorDiagnosticLogger.cs
@@ -3,9 +3,12 @@
 
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.IO;
 using Microsoft.Azure.WebJobs.Logging;
+using Microsoft.Azure.WebJobs.Script.Configuration;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Options;
 using Newtonsoft.Json;
 
 namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
@@ -15,24 +18,31 @@ public class AzureMonitorDiagnosticLogger : ILogger
         internal const string AzureMonitorCategoryName = "FunctionAppLogs";
         internal const string AzureMonitorOperationName = "Microsoft.Web/sites/functions/log";
 
+        private static int _processId = Process.GetCurrentProcess().Id;
+
         private readonly string _hostVersion = ScriptHost.Version;
         private readonly string _regionName;
         private readonly string _category;
         private readonly string _hostInstanceId;
-
+        private readonly string _roleInstance;
         private readonly HostNameProvider _hostNameProvider;
+        private readonly IOptionsMonitor<AppServiceOptions> _appServiceOptions;
         private readonly IEventGenerator _eventGenerator;
         private readonly IEnvironment _environment;
         private readonly IExternalScopeProvider _scopeProvider;
 
-        public AzureMonitorDiagnosticLogger(string category, string hostInstanceId, IEventGenerator eventGenerator, IEnvironment environment, IExternalScopeProvider scopeProvider, HostNameProvider hostNameProvider)
+        public AzureMonitorDiagnosticLogger(string category, string hostInstanceId, IEventGenerator eventGenerator, IEnvironment environment, IExternalScopeProvider scopeProvider,
+            HostNameProvider hostNameProvider, IOptionsMonitor<AppServiceOptions> appServiceOptions)
         {
             _category = category ?? throw new ArgumentNullException(nameof(category));
             _hostInstanceId = hostInstanceId ?? throw new ArgumentNullException(nameof(hostInstanceId));
             _eventGenerator = eventGenerator ?? throw new ArgumentNullException(nameof(eventGenerator));
             _environment = environment ?? throw new ArgumentNullException(nameof(environment));
             _scopeProvider = scopeProvider ?? throw new ArgumentNullException(nameof(scopeProvider));
             _hostNameProvider = hostNameProvider ?? throw new ArgumentNullException(nameof(hostNameProvider));
+            _appServiceOptions = appServiceOptions ?? throw new ArgumentNullException(nameof(appServiceOptions));
+
+            _roleInstance = _environment.GetInstanceId();
 
             _regionName = _environment.GetEnvironmentVariable(EnvironmentSettingNames.RegionName) ?? string.Empty;
         }
@@ -61,6 +71,10 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
             }
 
             (string exceptionType, string exceptionMessage, string exceptionDetails) = exception.GetExceptionDetails();
+            if (exception != null)
+            {
+                formattedMessage = Sanitizer.Sanitize(formattedMessage);
+            }
 
             var scopeProps = _scopeProvider.GetScopeDictionary();
             var stateProps = state as IEnumerable<KeyValuePair<string, object>> ?? new Dictionary<string, object>();
@@ -70,30 +84,47 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
             using (JsonTextWriter writer = new JsonTextWriter(sw) { Formatting = Formatting.None })
             {
                 writer.WriteStartObject();
-                WritePropertyIfNotNull(writer, "message", Sanitizer.Sanitize(formattedMessage));
+                WritePropertyIfNotNull(writer, "appName", _appServiceOptions.CurrentValue.AppName);
+                WritePropertyIfNotNull(writer, "roleInstance", _roleInstance);
+                WritePropertyIfNotNull(writer, "message", formattedMessage);
                 WritePropertyIfNotNull(writer, "category", _category);
                 WritePropertyIfNotNull(writer, "hostVersion", _hostVersion);
                 WritePropertyIfNotNull(writer, "functionInvocationId", Utility.GetValueFromScope(scopeProps, ScopeKeys.FunctionInvocationId));
                 WritePropertyIfNotNull(writer, "functionName", Utility.ResolveFunctionName(stateProps, scopeProps));
                 WritePropertyIfNotNull(writer, "hostInstanceId", _hostInstanceId);
                 WritePropertyIfNotNull(writer, "activityId", Utility.GetValueFromScope(scopeProps, ScriptConstants.LogPropertyActivityIdKey));
                 WritePropertyIfNotNull(writer, "level", logLevel.ToString());
+                WritePropertyIfNotNull(writer, "levelId", (int)logLevel);
+                WritePropertyIfNotNull(writer, "processId", _processId);
                 WritePropertyIfNotNull(writer, nameof(exceptionDetails), exceptionDetails);
                 WritePropertyIfNotNull(writer, nameof(exceptionMessage), exceptionMessage);
                 WritePropertyIfNotNull(writer, nameof(exceptionType), exceptionType);
+
+                // Only write the event if it's relevant
+                if (eventId.Id != 0 || !string.IsNullOrEmpty(eventId.Name))
+                {
+                    WriteProperty(writer, "eventId", eventId.Id);
+                    WriteProperty(writer, "eventName", eventId.Name);
+                }
+
                 writer.WriteEndObject();
             }
 
             _eventGenerator.LogAzureMonitorDiagnosticLogEvent(logLevel, _hostNameProvider.Value, AzureMonitorOperationName, AzureMonitorCategoryName, _regionName, sw.ToString());
         }
 
-        private static void WritePropertyIfNotNull(JsonTextWriter writer, string propertyName, string propertyValue)
+        private static void WritePropertyIfNotNull<T>(JsonTextWriter writer, string propertyName, T propertyValue)
         {
             if (propertyValue != null)
             {
-                writer.WritePropertyName(propertyName);
-                writer.WriteValue(propertyValue);
+                WriteProperty(writer, propertyName, propertyValue);
             }
         }
+
+        private static void WriteProperty<T>(JsonTextWriter writer, string propertyName, T propertyValue)
+        {
+            writer.WritePropertyName(propertyName);
+            writer.WriteValue(propertyValue);
+        }
     }
 }
diff --git a/src/WebJobs.Script.WebHost/Diagnostics/AzureMonitorDiagnosticLoggerProvider.cs b/src/WebJobs.Script.WebHost/Diagnostics/AzureMonitorDiagnosticLoggerProvider.cs
@@ -2,6 +2,7 @@
 // Licensed under the MIT License. See License.txt in the project root for license information.
 
 using System;
+using Microsoft.Azure.WebJobs.Script.Configuration;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
 
@@ -13,24 +14,28 @@ public class AzureMonitorDiagnosticLoggerProvider : ILoggerProvider, ISupportExt
         private readonly IEventGenerator _eventGenerator;
         private readonly IEnvironment _environment;
         private readonly HostNameProvider _hostNameProvider;
+        private readonly IOptionsMonitor<AppServiceOptions> _appServiceOptions;
         private IExternalScopeProvider _scopeProvider;
 
-        public AzureMonitorDiagnosticLoggerProvider(IOptions<ScriptJobHostOptions> scriptOptions, IEventGenerator eventGenerator, IEnvironment environment, HostNameProvider hostNameProvider)
-            : this(scriptOptions.Value.InstanceId, eventGenerator, environment, hostNameProvider)
+        public AzureMonitorDiagnosticLoggerProvider(IOptions<ScriptJobHostOptions> scriptOptions, IEventGenerator eventGenerator, IEnvironment environment,
+            HostNameProvider hostNameProvider, IOptionsMonitor<AppServiceOptions> appServiceOptions)
+            : this(scriptOptions.Value.InstanceId, eventGenerator, environment, hostNameProvider, appServiceOptions)
         {
         }
 
-        public AzureMonitorDiagnosticLoggerProvider(string hostInstanceId, IEventGenerator eventGenerator, IEnvironment environment, HostNameProvider hostNameProvider)
+        public AzureMonitorDiagnosticLoggerProvider(string hostInstanceId, IEventGenerator eventGenerator, IEnvironment environment,
+            HostNameProvider hostNameProvider, IOptionsMonitor<AppServiceOptions> appServiceOptions)
         {
             _hostInstanceId = hostInstanceId ?? throw new ArgumentNullException(hostInstanceId);
             _eventGenerator = eventGenerator ?? throw new ArgumentNullException(nameof(eventGenerator));
             _environment = environment ?? throw new ArgumentException(nameof(environment));
             _hostNameProvider = hostNameProvider ?? throw new ArgumentException(nameof(hostNameProvider));
+            _appServiceOptions = appServiceOptions ?? throw new ArgumentNullException(nameof(appServiceOptions));
         }
 
         public ILogger CreateLogger(string categoryName)
         {
-            return new AzureMonitorDiagnosticLogger(categoryName, _hostInstanceId, _eventGenerator, _environment, _scopeProvider, _hostNameProvider);
+            return new AzureMonitorDiagnosticLogger(categoryName, _hostInstanceId, _eventGenerator, _environment, _scopeProvider, _hostNameProvider, _appServiceOptions);
         }
 
         public void Dispose()
diff --git a/src/WebJobs.Script/Environment/EnvironmentExtensions.cs b/src/WebJobs.Script/Environment/EnvironmentExtensions.cs
@@ -243,6 +243,21 @@ public static string GetAzureWebsiteUniqueSlotName(this IEnvironment environment
             return name?.ToLowerInvariant();
         }
 
+        /// <summary>
+        /// Gets the Instance id.
+        /// </summary>
+        public static string GetInstanceId(this IEnvironment environment)
+        {
+            if (environment.IsLinuxConsumption())
+            {
+                return environment.GetEnvironmentVariableOrDefault(ContainerName, string.Empty);
+            }
+            else
+            {
+                return environment.GetEnvironmentVariableOrDefault(AzureWebsiteInstanceId, string.Empty);
+            }
+        }
+
         /// <summary>
         /// Gets a the subscription Id of the current site.
         /// </summary>
diff --git a/test/WebJobs.Script.Tests/Eventing/DiagnosticLoggerTests.cs b/test/WebJobs.Script.Tests/Eventing/DiagnosticLoggerTests.cs
@@ -3,7 +3,9 @@
 
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using Microsoft.Azure.WebJobs.Logging;
+using Microsoft.Azure.WebJobs.Script.Configuration;
 using Microsoft.Azure.WebJobs.Script.WebHost;
 using Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics;
 using Microsoft.Extensions.Logging;
@@ -20,11 +22,14 @@ public class DiagnosticLoggerTests
         private static readonly string _regionName = "West US";
         private static readonly string _websiteHostName = "functionstest.azurewebsites.net";
         private static readonly string _subscriptionId = "e3235165-1600-4819-85f0-2ab362e909e4";
+        private static readonly string _roleInstance = "e777fde04dea4eb931d5e5f06e65b4fdf5b375aed60af41dd7b491cf5792e01b";
+        private static readonly int _processId = Process.GetCurrentProcess().Id;
         private readonly string _hostInstanceId = Guid.NewGuid().ToString();
 
         private readonly AzureMonitorDiagnosticLogger _logger;
         private readonly Mock<IEventGenerator> _mockEventGenerator;
         private readonly IEnvironment _environment = new TestEnvironment();
+        private readonly TestOptionsMonitor<AppServiceOptions> _appServiceOptionsWrapper;
         private readonly string _category = LogCategories.CreateFunctionCategory(_functionName);
         private readonly HostNameProvider _hostNameProvider;
 
@@ -33,15 +38,26 @@ public DiagnosticLoggerTests()
             _environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteOwnerName, $"{_subscriptionId}+westuswebspace");
             _environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteHostName, _websiteHostName);
             _environment.SetEnvironmentVariable(EnvironmentSettingNames.RegionName, _regionName);
+            _environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteInstanceId, _roleInstance);
 
             _mockEventGenerator = new Mock<IEventGenerator>(MockBehavior.Strict);
 
+            var appServiceOptions = new AppServiceOptions
+            {
+                AppName = "TestApp",
+                SlotName = "Production",
+                SubscriptionId = "abc123",
+                RuntimeSiteName = "TestApp_Runtime"
+            };
+
+            _appServiceOptionsWrapper = new TestOptionsMonitor<AppServiceOptions>(appServiceOptions);
+
             _category = LogCategories.CreateFunctionCategory(_functionName);
             var loggerProvider = new TestLoggerProvider();
             var loggerFactory = new LoggerFactory();
             loggerFactory.AddProvider(loggerProvider);
             _hostNameProvider = new HostNameProvider(_environment);
-            _logger = new AzureMonitorDiagnosticLogger(_category, _hostInstanceId, _mockEventGenerator.Object, _environment, new LoggerExternalScopeProvider(), _hostNameProvider);
+            _logger = new AzureMonitorDiagnosticLogger(_category, _hostInstanceId, _mockEventGenerator.Object, _environment, new LoggerExternalScopeProvider(), _hostNameProvider, _appServiceOptionsWrapper);
         }
 
         [Fact]
@@ -61,22 +77,30 @@ public void Log_EmitsExpectedEvent()
 
             using (CreateScope(activityId: activityId, functionName: _functionName, functionInvocationId: functionInvocationId))
             {
-                _logger.LogDebug(message);
+                _logger.LogDebug(new EventId(123, "TestEvent"), message);
             }
 
             _mockEventGenerator.VerifyAll();
 
             JObject actual = JObject.Parse(properties);
+
+            var level = LogLevel.Debug;
             JObject expected = JObject.FromObject(new
             {
+                appName = _appServiceOptionsWrapper.CurrentValue.AppName,
+                roleInstance = _roleInstance,
                 message,
                 category = _category,
                 hostVersion = ScriptHost.Version,
                 functionInvocationId,
                 functionName = _functionName,
                 hostInstanceId = _hostInstanceId,
                 activityId,
-                level = "Debug"
+                level = level.ToString(),
+                levelId = (int)level,
+                processId = _processId,
+                eventId = 123,
+                eventName = "TestEvent"
             });
 
             Assert.True(JToken.DeepEquals(actual, expected), $"Actual: {actual.ToString()}{Environment.NewLine}Expected: {expected.ToString()}");
@@ -107,17 +131,23 @@ public void Log_Error_EmitsExpectedEvent()
 
             _mockEventGenerator.VerifyAll();
 
+            var level = LogLevel.Error;
+
             JObject actual = JObject.Parse(properties);
             JObject expected = JObject.FromObject(new
             {
+                appName = _appServiceOptionsWrapper.CurrentValue.AppName,
+                roleInstance = _roleInstance,
                 exceptionType = ex.GetType().ToString(),
                 exceptionMessage = ex.Message,
                 exceptionDetails = ex.ToFormattedString(),
                 message,
                 category = _category,
                 hostInstanceId = _hostInstanceId,
                 hostVersion = ScriptHost.Version,
-                level = "Error"
+                level = level.ToString(),
+                levelId = (int)level,
+                processId = _processId
             });
 
             Assert.True(JToken.DeepEquals(actual, expected), $"Actual: {actual.ToString()}{Environment.NewLine}Expected: {expected.ToString()}");
@@ -152,9 +182,13 @@ public void Log_Sanitizes()
 
             _mockEventGenerator.VerifyAll();
 
+            var level = LogLevel.Error;
+
             JObject actual = JObject.Parse(properties);
             JObject expected = JObject.FromObject(new
             {
+                appName = _appServiceOptionsWrapper.CurrentValue.AppName,
+                roleInstance = _roleInstance,
                 category = _category,
                 exceptionDetails = sanitizedDetails,
                 exceptionMessage = sanitizedExceptionMessage,
@@ -163,8 +197,10 @@ public void Log_Sanitizes()
                 functionName = _functionName,
                 hostInstanceId = _hostInstanceId,
                 hostVersion = ScriptHost.Version,
-                level = "Error",
+                level = level.ToString(),
+                levelId = (int)level,
                 message = sanitizedString,
+                processId = _processId
             });
 
             Assert.True(JToken.DeepEquals(actual, expected), $"Actual: {actual.ToString()}{Environment.NewLine}Expected: {expected.ToString()}");
@@ -194,7 +230,7 @@ public void Log_DisabledIfNoSiteName()
             _environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteHostName, null);
 
             // Recreate the logger was we cache the site name in the constructor
-            ILogger logger = new AzureMonitorDiagnosticLogger(_category, _hostInstanceId, _mockEventGenerator.Object, _environment, new LoggerExternalScopeProvider(), _hostNameProvider);
+            ILogger logger = new AzureMonitorDiagnosticLogger(_category, _hostInstanceId, _mockEventGenerator.Object, _environment, new LoggerExternalScopeProvider(), _hostNameProvider, _appServiceOptionsWrapper);
 
             logger.LogInformation(message);
 

Original file line number	Diff line number	Diff line change
`@@ -2,6 +2,7 @@`
`2`	`2`	`// Licensed under the MIT License. See License.txt in the project root for license information.`
`3`	`3`
`4`	`4`	`using System;`
	`5`	`+using Microsoft.Azure.WebJobs.Script.Configuration;`
`5`	`6`	`using Microsoft.Extensions.Logging;`
`6`	`7`	`using Microsoft.Extensions.Options;`
`7`	`8`
`@@ -13,24 +14,28 @@ public class AzureMonitorDiagnosticLoggerProvider : ILoggerProvider, ISupportExt`
`13`	`14`	`private readonly IEventGenerator _eventGenerator;`
`14`	`15`	`private readonly IEnvironment _environment;`
`15`	`16`	`private readonly HostNameProvider _hostNameProvider;`
	`17`	`+ private readonly IOptionsMonitor<AppServiceOptions> _appServiceOptions;`
`16`	`18`	`private IExternalScopeProvider _scopeProvider;`
`17`	`19`
`18`		`- public AzureMonitorDiagnosticLoggerProvider(IOptions<ScriptJobHostOptions> scriptOptions, IEventGenerator eventGenerator, IEnvironment environment, HostNameProvider hostNameProvider)`
`19`		`- : this(scriptOptions.Value.InstanceId, eventGenerator, environment, hostNameProvider)`
	`20`	`+ public AzureMonitorDiagnosticLoggerProvider(IOptions<ScriptJobHostOptions> scriptOptions, IEventGenerator eventGenerator, IEnvironment environment,`
	`21`	`+ HostNameProvider hostNameProvider, IOptionsMonitor<AppServiceOptions> appServiceOptions)`
	`22`	`+ : this(scriptOptions.Value.InstanceId, eventGenerator, environment, hostNameProvider, appServiceOptions)`
`20`	`23`	`{`
`21`	`24`	`}`
`22`	`25`
`23`		`- public AzureMonitorDiagnosticLoggerProvider(string hostInstanceId, IEventGenerator eventGenerator, IEnvironment environment, HostNameProvider hostNameProvider)`
	`26`	`+ public AzureMonitorDiagnosticLoggerProvider(string hostInstanceId, IEventGenerator eventGenerator, IEnvironment environment,`
	`27`	`+ HostNameProvider hostNameProvider, IOptionsMonitor<AppServiceOptions> appServiceOptions)`
`24`	`28`	`{`
`25`	`29`	`_hostInstanceId = hostInstanceId ?? throw new ArgumentNullException(hostInstanceId);`
`26`	`30`	`_eventGenerator = eventGenerator ?? throw new ArgumentNullException(nameof(eventGenerator));`
`27`	`31`	`_environment = environment ?? throw new ArgumentException(nameof(environment));`
`28`	`32`	`_hostNameProvider = hostNameProvider ?? throw new ArgumentException(nameof(hostNameProvider));`
	`33`	`+ _appServiceOptions = appServiceOptions ?? throw new ArgumentNullException(nameof(appServiceOptions));`
`29`	`34`	`}`
`30`	`35`
`31`	`36`	`public ILogger CreateLogger(string categoryName)`
`32`	`37`	`{`
`33`		`- return new AzureMonitorDiagnosticLogger(categoryName, _hostInstanceId, _eventGenerator, _environment, _scopeProvider, _hostNameProvider);`
	`38`	`+ return new AzureMonitorDiagnosticLogger(categoryName, _hostInstanceId, _eventGenerator, _environment, _scopeProvider, _hostNameProvider, _appServiceOptions);`
`34`	`39`	`}`
`35`	`40`
`36`	`41`	`public void Dispose()`