EventCounters event is written to an EventListener that never subscribed to it

[pakrym]

We have an EventListener listener where the subscription is guarded by a trait that System.Runtime event source doesn't have (TraitName = "AzureEventSource")

  protected sealed override void OnEventSourceCreated(EventSource eventSource)
        {
            base.OnEventSourceCreated(eventSource);

            if (eventSource.GetTrait(TraitName) == TraitValue)
            {
                EnableEvents(eventSource, _level);
            }
        }

Somehow without subscribing to System.Runtime event source we get EventCounters events with the following stack:

>	Azure.Core.dll!Azure.Core.Diagnostics.AzureEventSourceListener.OnEventWritten(System.Diagnostics.Tracing.EventWrittenEventArgs eventData) Line 70	C#
 	System.Private.CoreLib.dll!System.Diagnostics.Tracing.EventSource.DispatchToAllListeners(int eventId, System.Guid* childActivityID, System.Diagnostics.Tracing.EventWrittenEventArgs eventCallbackArgs) Line 2166	C#
 	System.Private.CoreLib.dll!System.Diagnostics.Tracing.EventSource.WriteToAllListeners(string eventName, ref System.Diagnostics.Tracing.EventDescriptor eventDescriptor, System.Diagnostics.Tracing.EventTags tags, System.Guid* pActivityId, System.Guid* pChildActivityId, System.Diagnostics.Tracing.EventPayload payload) Line 747	C#
 	System.Private.CoreLib.dll!System.Diagnostics.Tracing.EventSource.WriteImpl(string eventName, ref System.Diagnostics.Tracing.EventSourceOptions options, object data, System.Guid* pActivityId, System.Guid* pRelatedActivityId, System.Diagnostics.Tracing.TraceLoggingEventTypes eventTypes) Line 695	C#
 	System.Private.CoreLib.dll!System.Diagnostics.Tracing.PollingCounter.WritePayload(float intervalSec, int pollingIntervalMillisec) Line 76	C#
 	System.Private.CoreLib.dll!System.Diagnostics.Tracing.CounterGroup.OnTimer() Line 224	C#
 	System.Private.CoreLib.dll!System.Diagnostics.Tracing.CounterGroup.PollForValues() Line 251	C#
 	System.Private.CoreLib.dll!System.Threading.ThreadHelper.ThreadStart() Line 100	C#

EventData:

  | Name | Value | Type
-- | -- | -- | --
◢ | eventData | {System.Diagnostics.Tracing.EventWrittenEventArgs} | System.Diagnostics.Tracing.EventWrittenEventArgs
  | ▶ ActivityId | {00000000-0000-0000-0000-000000000000} | System.Guid
  | Channel | None | System.Diagnostics.Tracing.EventChannel
  | EventId | -1 | int
  | EventName | "EventCounters" | string
  | ▶ EventSource | {EventSource(System.Runtime, 49592c0f-5a05-516d-aa4b-a64e02026c89)} | System.Diagnostics.Tracing.EventSource {System.Diagnostics.Tracing.RuntimeEventSource}
  | Keywords | None | System.Diagnostics.Tracing.EventKeywords
  | Level | LogAlways | System.Diagnostics.Tracing.EventLevel
  | Message | null | string
  | OSThreadId | 36244 | long
  | Opcode | Info | System.Diagnostics.Tracing.EventOpcode
  | ▶ Payload | Count = 1 | System.Collections.ObjectModel.ReadOnlyCollection<object>
  | ▶ PayloadNames | Count = 1 | System.Collections.ObjectModel.ReadOnlyCollection<string>
  | ▶ RelatedActivityId | {00000000-0000-0000-0000-000000000000} | System.Guid
  | Tags | None | System.Diagnostics.Tracing.EventTags
  | Task | None | System.Diagnostics.Tracing.EventTask
  | ▶ TimeStamp | {11/14/2019 7:38:14 PM} | System.DateTime
  | Version | 0 | byte

Runtime version: 3.0.0

cc @noahfalk

[sywhang]

Do you know if there any EventPipe/ETW session that subscribed to System.Runtime? EventCounters are not session-aware so if an out-of-proc session has been started it is possible for EventListeners to start receiving payloads from EventSource that another session started.

[pakrym]

I'm using ApplicationInsights in the same app so maybe.

[sywhang]

AFAIK AppInsights does have an EventListener that turns on System.Runtime, so this is working as it was designed. I'll close this issue since it is a dup of https://github.com/dotnet/coreclr/issues/25262.

[pakrym]

That issue seems to be about refresh rates of event counters and subscibing to the same event source with different set of parameters. I don't see how it correlates with event being sent to the wrong eventlistener.

[sywhang]

Ah, sorry I should've clarified myself. To be more precise your issue is related to filtering on EventListener side - EventListener doesn't have the ability to filter on EventSource.Write. You can actually repro this same behavior happening with just a plain EventSource without any EventCounters.

For example, this EventSource will start spewing events out to any EventListener instance if there is a session that enables it:

    [EventSource(Name = "MyCompany")]
    class MyCompanyEventSource : EventSource
    {
        public void Failure(string message)
        {
            this.Write("MyCompany", new EventSourceOptions() { Level = EventLevel.LogAlways }, new CompanyPayloadType("Failure: " + message));
        }

        public void Startup()
        {
            this.Write("MyCompany", new EventSourceOptions() { Level = EventLevel.LogAlways }, new CompanyPayloadType("Startup"));
        }

        public void PageStart(int ID, string url)
        {
            if (IsEnabled())
            {
                this.Write("MyCompany", new EventSourceOptions() { Level = EventLevel.LogAlways }, new CompanyPayloadType("Page Started"));
            }
        }

        public void PageStop(int ID)
        {
            if (IsEnabled())
            {
                this.Write("MyCompany", new EventSourceOptions() { Level = EventLevel.LogAlways }, new CompanyPayloadType("Page Stopped"));
             }
         }

        public static MyCompanyEventSource Log = new MyCompanyEventSource();
    }

The culprit is here: https://github.com/dotnet/coreclr/blob/master/src/System.Private.CoreLib/shared/System/Diagnostics/Tracing/TraceLogging/TraceLoggingEventSource.cs#L684

I thought we had an issue tracking this but I couldn't find any, so I'll use this issue as tracking this work item. Thanks!

[tommcdon]

Duplicate to #31927