Add structured logging support to custom log states (#3005)

* Add structured logging support to custom log states.
* Make sure formatters don't capture locals.
* Update LoggerExtensions.cs
We ignore these `Aggregate`, `Result` and `Metric` logs and don't log it anywhere. We rely on the formatted message to ignore these logs (one example here https://github.com/Azure/azure-functions-host/blob/b42df4d4e63ab87f7a737f5a65dadf3eb7ba7de4/src/WebJobs.Script/Diagnostics/FileLogger.cs#L50). 
Setting the formatter to `null` so that we still ignore these.


---------

Co-authored-by: Rohit Ranjan <90008725+RohitRanjanMS@users.noreply.github.com>

src/Microsoft.Azure.WebJobs.Host/Loggers/Logger/Aggregator/FunctionResultAggregate.cs

@@ -2,8 +2,6 @@
 // Licensed under the MIT License. See License.txt in the project root for license information.
 
 using System;
-using System.Collections.Generic;
-using System.Collections.ObjectModel;
 
 namespace Microsoft.Azure.WebJobs.Logging
 {
@@ -18,21 +16,5 @@ internal class FunctionResultAggregate
         public int Failures { get; set; }
         public int Count => Successes + Failures;
         public double SuccessRate => Math.Round((Successes / (double)Count) * 100, 2);
-
-        public IReadOnlyDictionary<string, object> ToReadOnlyDictionary()
-        {
-            return new ReadOnlyDictionary<string, object>(new Dictionary<string, object>
-            {
-                [LogConstants.NameKey] = Name,
-                [LogConstants.CountKey] = Count,
-                [LogConstants.TimestampKey] = Timestamp,
-                [LogConstants.AverageDurationKey] = AverageDuration,
-                [LogConstants.MaxDurationKey] = MaxDuration,
-                [LogConstants.MinDurationKey] = MinDuration,
-                [LogConstants.SuccessesKey] = Successes,
-                [LogConstants.FailuresKey] = Failures,
-                [LogConstants.SuccessRateKey] = SuccessRate
-            });
-        }
     }
 }

src/Microsoft.Azure.WebJobs.Host/Loggers/Logger/LoggerExtensions.cs

@@ -3,7 +3,6 @@
 
 using System;
 using System.Collections.Generic;
-using System.Collections.ObjectModel;
 using Microsoft.Azure.WebJobs.Host.Executors;
 using Microsoft.Azure.WebJobs.Host.Loggers;
 using Microsoft.Azure.WebJobs.Logging;
@@ -196,41 +195,36 @@ public static void FunctionConcurrencyIncrease(this ILogger logger, string funct
         /// <param name="properties">Named string values for classifying and filtering metrics.</param>
         public static void LogMetric(this ILogger logger, string name, double value, IDictionary<string, object> properties = null)
         {
-            IDictionary<string, object> state = properties == null ? new Dictionary<string, object>() : new Dictionary<string, object>(properties);
-
-            state[LogConstants.NameKey] = name;
-            state[LogConstants.MetricValueKey] = value;
-
-            IDictionary<string, object> payload = new ReadOnlyDictionary<string, object>(state);
-            logger?.Log(LogLevel.Information, LogConstants.MetricEventId, payload, null, (s, e) => null);
+            logger?.Log(
+                LogLevel.Information,
+                LogConstants.MetricEventId,
+                new MetricState(name, value, properties),
+                null,
+                static (s, e) => null);
         }
 
         internal static void LogFunctionResult(this ILogger logger, FunctionInstanceLogEntry logEntry)
         {
             bool succeeded = logEntry.Exception == null;
 
-            IDictionary<string, object> payload = new Dictionary<string, object>(8)
-            {
-                { LogConstants.FullNameKey, logEntry.FunctionName },
-                { LogConstants.InvocationIdKey, logEntry.FunctionInstanceId },
-                { LogConstants.NameKey, logEntry.LogName },
-                { LogConstants.TriggerReasonKey, logEntry.TriggerReason },
-                { LogConstants.StartTimeKey, logEntry.StartTime },
-                { LogConstants.EndTimeKey, logEntry.EndTime },
-                { LogConstants.DurationKey, logEntry.Duration },
-                { LogConstants.SucceededKey, succeeded }
-            };
-
             LogLevel level = succeeded ? LogLevel.Information : LogLevel.Error;
 
-            // Only pass the state dictionary; no string message.
-            logger.Log(level, 0, payload, logEntry.Exception, (s, e) => null);
+            logger.Log(
+                level,
+                0,
+                new FunctionResultState(logEntry, succeeded),
+                logEntry.Exception,
+                static (s, e) => null);
         }
 
         internal static void LogFunctionResultAggregate(this ILogger logger, FunctionResultAggregate resultAggregate)
         {
-            // we won't output any string here, just the data
-            logger.Log(LogLevel.Information, 0, resultAggregate.ToReadOnlyDictionary(), null, (s, e) => null);
+            logger.Log(
+                LogLevel.Information,
+                0,
+                new FunctionResultAggregateState(resultAggregate),
+                null,
+                static (s, e) => null);
         }
 
         internal static IDisposable BeginFunctionScope(this ILogger logger, IFunctionInstance functionInstance, Guid hostInstanceId)

src/Microsoft.Azure.WebJobs.Host/Loggers/Logger/States/FunctionResultAggregateState.cs

@@ -0,0 +1,86 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using System.Collections;
+using System.Collections.Generic;
+
+namespace Microsoft.Azure.WebJobs.Logging
+{
+    internal readonly struct FunctionResultAggregateState : IReadOnlyList<KeyValuePair<string, object>>
+    {
+        public const string OriginalFormatString = "Aggregate result (function={Name}, count={Count}, time={Timestamp}, duration={AverageDuration}ms, maxDuration={MaxDuration}ms, minDuration={MinDuration}ms, success={Successes}, failure={Failures}, rate={SuccessRate})";
+        private readonly FunctionResultAggregate _resultAggregate;
+
+        public FunctionResultAggregateState(FunctionResultAggregate resultAggregate)
+        {
+            _resultAggregate = resultAggregate;
+        }
+
+        public KeyValuePair<string, object> this[int index]
+        {
+            get
+            {
+                return index switch
+                {
+                    0 => new KeyValuePair<string, object>(LogConstants.NameKey, _resultAggregate.Name),
+                    1 => new KeyValuePair<string, object>(LogConstants.CountKey, _resultAggregate.Count),
+                    2 => new KeyValuePair<string, object>(LogConstants.TimestampKey, _resultAggregate.Timestamp),
+                    3 => new KeyValuePair<string, object>(LogConstants.AverageDurationKey, _resultAggregate.AverageDuration),
+                    4 => new KeyValuePair<string, object>(LogConstants.MaxDurationKey, _resultAggregate.MaxDuration),
+                    5 => new KeyValuePair<string, object>(LogConstants.MinDurationKey, _resultAggregate.MinDuration),
+                    6 => new KeyValuePair<string, object>(LogConstants.SuccessesKey, _resultAggregate.Successes),
+                    7 => new KeyValuePair<string, object>(LogConstants.FailuresKey, _resultAggregate.Failures),
+                    8 => new KeyValuePair<string, object>(LogConstants.SuccessRateKey, _resultAggregate.SuccessRate),
+                    9 => new KeyValuePair<string, object>(LogConstants.OriginalFormatKey, OriginalFormatString),
+                    _ => throw new ArgumentOutOfRangeException(nameof(index)),
+                };
+            }
+        }
+
+        public int Count => 10;
+
+        public Enumerator GetEnumerator() => new Enumerator(this);
+
+        IEnumerator<KeyValuePair<string, object>> IEnumerable<KeyValuePair<string, object>>.GetEnumerator()
+            => GetEnumerator();
+
+        IEnumerator IEnumerable.GetEnumerator()
+            => GetEnumerator();
+
+        public override string ToString()
+        {
+            return $"Aggregate result (function={_resultAggregate.Name}, count={_resultAggregate.Count}, time={_resultAggregate.Timestamp}, duration={_resultAggregate.AverageDuration}ms, maxDuration={_resultAggregate.MaxDuration}ms, minDuration={_resultAggregate.MinDuration}ms, success={_resultAggregate.Successes}, failure={_resultAggregate.Failures}, rate={_resultAggregate.SuccessRate})";
+        }
+
+        public struct Enumerator : IEnumerator<KeyValuePair<string, object>>
+        {
+            private readonly FunctionResultAggregateState _state;
+            private int _index = -1;
+
+            public Enumerator(FunctionResultAggregateState state)
+            {
+                _state = state;
+            }
+
+            public readonly KeyValuePair<string, object> Current
+                => _state[_index];
+
+            readonly object IEnumerator.Current => Current;
+
+            public readonly void Dispose()
+            {
+            }
+
+            public bool MoveNext()
+            {
+                return ++_index < _state.Count;
+            }
+
+            public readonly void Reset()
+            {
+                throw new NotSupportedException();
+            }
+        }
+    }
+}

src/Microsoft.Azure.WebJobs.Host/Loggers/Logger/States/FunctionResultState.cs

@@ -0,0 +1,88 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using Microsoft.Azure.WebJobs.Host.Loggers;
+using System;
+using System.Collections;
+using System.Collections.Generic;
+
+namespace Microsoft.Azure.WebJobs.Logging
+{
+    internal readonly struct FunctionResultState : IReadOnlyList<KeyValuePair<string, object>>
+    {
+        public const string OriginalFormatString = "Result '{FunctionName}' (started at={StartTime}, duration={Duration}, succeeded={Succeeded})";
+        private readonly FunctionInstanceLogEntry _logEntry;
+        private readonly bool _succeeded;
+
+        public FunctionResultState(FunctionInstanceLogEntry logEntry, bool succeeded)
+        {
+            _logEntry = logEntry;
+            _succeeded = succeeded;
+        }
+
+        public KeyValuePair<string, object> this[int index]
+        {
+            get
+            {
+                return index switch
+                {
+                    0 => new KeyValuePair<string, object>(LogConstants.FullNameKey, _logEntry.FunctionName),
+                    1 => new KeyValuePair<string, object>(LogConstants.InvocationIdKey, _logEntry.FunctionInstanceId),
+                    2 => new KeyValuePair<string, object>(LogConstants.NameKey, _logEntry.LogName),
+                    3 => new KeyValuePair<string, object>(LogConstants.TriggerReasonKey, _logEntry.TriggerReason),
+                    4 => new KeyValuePair<string, object>(LogConstants.StartTimeKey, _logEntry.StartTime),
+                    5 => new KeyValuePair<string, object>(LogConstants.EndTimeKey, _logEntry.EndTime),
+                    6 => new KeyValuePair<string, object>(LogConstants.DurationKey, _logEntry.Duration),
+                    7 => new KeyValuePair<string, object>(LogConstants.SucceededKey, _succeeded),
+                    8 => new KeyValuePair<string, object>(LogConstants.OriginalFormatKey, OriginalFormatString),
+                    _ => throw new ArgumentOutOfRangeException(nameof(index)),
+                };
+            }
+        }
+
+        public int Count => 9;
+
+        public Enumerator GetEnumerator() => new Enumerator(this);
+
+        IEnumerator<KeyValuePair<string, object>> IEnumerable<KeyValuePair<string, object>>.GetEnumerator()
+            => GetEnumerator();
+
+        IEnumerator IEnumerable.GetEnumerator()
+            => GetEnumerator();
+
+        public override string ToString()
+        {
+            return $"Result '{_logEntry.FunctionName}' (started at={_logEntry.StartTime}, duration={_logEntry.Duration}, succeeded={_succeeded})";
+        }
+
+        public struct Enumerator : IEnumerator<KeyValuePair<string, object>>
+        {
+            private readonly FunctionResultState _state;
+            private int _index = -1;
+
+            public Enumerator(FunctionResultState state)
+            {
+                _state = state;
+            }
+
+            public readonly KeyValuePair<string, object> Current
+                => _state[_index];
+
+            readonly object IEnumerator.Current => Current;
+
+            public readonly void Dispose()
+            {
+            }
+
+            public bool MoveNext()
+            {
+                return ++_index < _state.Count;
+            }
+
+            public readonly void Reset()
+            {
+                throw new NotSupportedException();
+            }
+        }
+    }
+}

src/Microsoft.Azure.WebJobs.Host/Loggers/Logger/States/MetricState.cs

@@ -0,0 +1,105 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+using System;
+using System.Collections;
+using System.Collections.Generic;
+using System.Linq;
+
+namespace Microsoft.Azure.WebJobs.Logging
+{
+    internal readonly struct MetricState : IReadOnlyList<KeyValuePair<string, object>>
+    {
+        public const string OriginalFormatString = "Metric {Name} {Value}";
+        private readonly string _name;
+        private readonly double _value;
+        private readonly IReadOnlyList<KeyValuePair<string, object>> _properties;
+
+        public MetricState(string name, double value, IDictionary<string, object> properties)
+        {
+            _name = name;
+            _value = value;
+            _properties = properties?.ToList();
+        }
+
+        public KeyValuePair<string, object> this[int index]
+        {
+            get
+            {
+                if (index == 0)
+                {
+                    return new KeyValuePair<string, object>(LogConstants.NameKey, _name);
+                }
+
+                if (index == 1)
+                {
+                    return new KeyValuePair<string, object>(LogConstants.MetricValueKey, _value);
+                }
+
+                index -= 2;
+
+                if (_properties != null)
+                {
+                    if (index < _properties.Count)
+                    {
+                        return _properties[index];
+                    }
+
+                    index -= _properties.Count;
+                }
+
+                if (index == 0)
+                {
+                    return new KeyValuePair<string, object>(LogConstants.OriginalFormatKey, OriginalFormatString);
+                }
+
+                throw new ArgumentOutOfRangeException(nameof(index));
+            }
+        }
+
+        public int Count => 3 + (_properties?.Count ?? 0);
+
+        public Enumerator GetEnumerator() => new Enumerator(this);
+
+        IEnumerator<KeyValuePair<string, object>> IEnumerable<KeyValuePair<string, object>>.GetEnumerator()
+            => GetEnumerator();
+
+        IEnumerator IEnumerable.GetEnumerator()
+            => GetEnumerator();
+
+        public override string ToString()
+        {
+            return $"Metric {_name} {_value}";
+        }
+
+        public struct Enumerator : IEnumerator<KeyValuePair<string, object>>
+        {
+            private readonly MetricState _state;
+            private int _index = -1;
+
+            public Enumerator(MetricState state)
+            {
+                _state = state;
+            }
+
+            public readonly KeyValuePair<string, object> Current
+                => _state[_index];
+
+            readonly object IEnumerator.Current => Current;
+
+            public readonly void Dispose()
+            {
+            }
+
+            public bool MoveNext()
+            {
+                return ++_index < _state.Count;
+            }
+
+            public readonly void Reset()
+            {
+                throw new NotSupportedException();
+            }
+        }
+    }
+}