Azure/diagnostics-eventflow

IFilter custom properties seem to break AzureMonitor Output

berndku opened this issue · 4 comments

Below custom IFilter adds a few properties to the payload using AddPayloadProperty.
Configured as GlobalFilter, this works perfectly e.g. with HttpOutput, but if we try to use it with OmsOutput / AzureMonitorLogs output, we see suddenly no more log entries in Azure Monitor.
We also simplified the implementation by just adding AddPayloadProperty("Abc", "Abc", …) and got the same issue.
If we use eventData.Payload.Add instead of AddPayloadProperty, we can exactly add one custom property and the message shows up in Azure Monitor. But if we add two properties, the log messages no longer appear in Azure Monitor.

It seems the OmsOutput has a problem with additional custom properties. Any help would be much appreciated.

 public class ServiceFabricFilter : IFilter
    {
        private const string CONTEXT = "ServiceFabricFilter";
        private ServiceContext _context;

        private IHealthReporter _healthReporter;
        
        public ServiceFabricFilter(IHealthReporter healthReporter)
        {
            _healthReporter = healthReporter;
        }

        internal void SetServiceContext(ServiceContext context)
        {
            _context = context;
        }
        
        public FilterResult Evaluate(EventData eventData)
        {
            if (_context != null)
            {
                eventData.AddPayloadProperty(KnownContextFieldNames.ServiceName, _context.ServiceName.ToString(), _healthReporter, CONTEXT);
                eventData.AddPayloadProperty(KnownContextFieldNames.ServiceTypeName, _context.ServiceTypeName, _healthReporter, CONTEXT);
                eventData.AddPayloadProperty(KnownContextFieldNames.PartitionId, _context.PartitionId.ToString(), _healthReporter, CONTEXT);
                eventData.AddPayloadProperty(KnownContextFieldNames.ApplicationName, _context.CodePackageActivationContext.ApplicationName, _healthReporter, CONTEXT);
                eventData.AddPayloadProperty(KnownContextFieldNames.ApplicationTypeName, _context.CodePackageActivationContext.ApplicationTypeName, _healthReporter, CONTEXT);
                eventData.AddPayloadProperty(KnownContextFieldNames.NodeName, _context.NodeContext.NodeName, _healthReporter, CONTEXT);
                if (_context is StatelessServiceContext)
                {
                    eventData.AddPayloadProperty(KnownContextFieldNames.InstanceId, _context.ReplicaOrInstanceId.ToString(CultureInfo.InvariantCulture), _healthReporter, CONTEXT);
                }

                if (_context is StatefulServiceContext)
                {
                    eventData.AddPayloadProperty(KnownContextFieldNames.ReplicaId, _context.ReplicaOrInstanceId.ToString(CultureInfo.InvariantCulture), _healthReporter, CONTEXT);
                }
            }
            return FilterResult.KeepEvent;
        }

        private class KnownContextFieldNames
        {
            public const string ServiceName = "ServiceName";
            public const string ServiceTypeName = "ServiceTypeName";
            public const string PartitionId = "PartitionId";
            public const string ApplicationName = "ApplicationName";
            public const string ApplicationTypeName = "ApplicationTypeName";
            public const string NodeName = "NodeName";
            public const string InstanceId = "InstanceId";
            public const string ReplicaId = "ReplicaId";
        }
    }

That is not expected. Let me see if I can reproduce this issue...

I cannot reproduce the issue

Project:

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>netcoreapp2.2</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.Diagnostics.EventFlow.Inputs.MicrosoftLogging" Version="1.4.0" />
    <PackageReference Include="Microsoft.Diagnostics.EventFlow.Outputs.AzureMonitorLogs" Version="1.6.0" />
    <PackageReference Include="Microsoft.Diagnostics.EventFlow.Outputs.StdOutput" Version="1.4.1" />
  </ItemGroup>

</Project>

CustomFilter.cs

class CustomFilter : IFilter
    {
        private static readonly string Context = "Application";

        private IHealthReporter healthReporter_;

        public CustomFilter(IHealthReporter healthReporter)
        {
            Requires.NotNull(healthReporter, nameof(healthReporter));
            healthReporter_ = healthReporter;
        }

        public FilterResult Evaluate(EventData eventData)
        {
            eventData.AddPayloadProperty("Alpha", "aaa", healthReporter_, Context);
            eventData.AddPayloadProperty("Bravo", "bbb", healthReporter_, Context);
            eventData.AddPayloadProperty("Charlie", "ccc", healthReporter_, Context);
            eventData.AddPayloadProperty("CurrentTime", DateTime.UtcNow.ToString("o"), healthReporter_, Context);
            return FilterResult.KeepEvent;
        }
    }

Program.cs

class Program
    {
        static void Main(string[] args)
        {
            var healthReporter = new CsvHealthReporter(new CsvHealthReporterConfiguration());

            var loggerInput = new LoggerInput(healthReporter);
            var inputs = new IObservable<EventData>[] { loggerInput };
            var loggerFactory = new LoggerFactory();
            loggerFactory.AddProvider(new EventFlowLoggerProvider(loggerInput, healthReporter));

            var globalFilters = new IFilter[] { new CustomFilter(healthReporter) };

            var sinks = new EventSink[] {
                new EventSink(new StdOutput(healthReporter), null),
                new EventSink(new OmsOutput(new OmsOutputConfiguration {
                    WorkspaceId = "xxx-xx-xx",
                    WorkspaceKey = "yyy-yy-yy=="
                }, healthReporter), null)
            };

            using (var pipeline = new DiagnosticPipeline(healthReporter, inputs, globalFilters, sinks)) {
                var logger = new Logger<Program>(loggerFactory);
                logger.LogInformation("Will this message get more proprties?");
            }

            Console.WriteLine("Done! Press any key to exit");
            Console.ReadKey(intercept: true);
        }
    }

I can see Payload_Alpha_s Payload_Bravo_s Payload_Charlie_s and Payload_CurrentTime_t in Log Analytics just fine

Many thanks for the working sample, it was a great help for analyzing the root cause of the issue.
It turned out EventFlow was working just fine and sent all the properties to Azure Monitor.
Unfortunately the Azure Monitor table reached the max limit of 500 columns. In this case it seems that if data is ingested that contains a new property, the whole row is discarded, though the Collector API returns 200. I assume the data is purged during indexing in Azure Monitor. That´s why logs without custom properties did show up, but logs with additional properties don´t. After changing to a fresh new table, everything works as expected.

Interesting. Thanks for figuring out the root cause!