Skip to content

Enable EventListener filtering#39117

Closed
sywhang wants to merge 20 commits intodotnet:masterfrom
sywhang:dev/suwhang/eventlistener-filtering
Closed

Enable EventListener filtering#39117
sywhang wants to merge 20 commits intodotnet:masterfrom
sywhang:dev/suwhang/eventlistener-filtering

Conversation

@sywhang
Copy link
Contributor

@sywhang sywhang commented Jul 10, 2020

Fixes #31927 and #31500.

This enables filtering for EventListeners - currently instances of EventListeners may receive callbacks for OnEventWritten for events that it never called EnableEvent on, because it does not keep track of the providers/keywords/level that it called EnableEvent() on.

This PR addresses the issue by managing the state of enabled providers in each instances of EventListener, and filtering events before dispatching the callback.

Because this may break existing EventListeners that were getting more events that they were supposed to (i.e. an EventListener that was receiving runtime events that it never subscribed to, but only because there was another session/EventListener that turned it on), an AppCompat switch was added to opt out of the filtering behavior.

Debug.Assert(dispatcher.m_EventEnabled != null);
if (eventId == -1 || dispatcher.m_EventEnabled[eventId])
if (LocalAppContextSwitches.DisableEventListenerFiltering ||
(dispatcher.m_EventEnabled[eventId] && dispatcher.m_Listener.IsEventEnabled(eventCallbackArgs)))
Copy link
Member

@stephentoub stephentoub Jul 11, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there any way to restructure WriteToAllListeners (both overloads) / DispatchToAllListeners such that we can delay creating/populating the EventWrittenEventArgs until / if it's actually needed the first time? As it stands, it seems like we're creating the fairly-expensive per-event object even if it'll never be used.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I just took a second look and yes, I think I should be able to by querying whether any of the listeners have the events enabled before calling WriteToAllListeners from WriteImpl - this would mean that in the case it is actually enabled by an instance of listener, it needs incur a little bit of more perf cost (since needs to filter it again at the DispatchToAllListeners) but I think it still makes sense to do what you said for the sake of pay-for-play. I'll give that a try. Thanks Stephen!

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We already have a check "event[eventId].enabledForAnyListener" that precedes the object construction.

if (m_Dispatchers != null && m_eventData[eventId].EnabledForAnyListener)

Similar to above, if these filters aren't working it would be good to understand why not and if they should be fixed vs. creating a second filtering implementation.

Copy link
Member

@noahfalk noahfalk left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should better understand the state of the existing Dispatcher.m_EventEnabled filtering mechanism before adding a 2nd scheme.

Debug.Assert(dispatcher.m_EventEnabled != null);
if (eventId == -1 || dispatcher.m_EventEnabled[eventId])
if (LocalAppContextSwitches.DisableEventListenerFiltering ||
(dispatcher.m_EventEnabled[eventId] && dispatcher.m_Listener.IsEventEnabled(eventCallbackArgs)))
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We already have a check "event[eventId].enabledForAnyListener" that precedes the object construction.

if (m_Dispatchers != null && m_eventData[eventId].EnabledForAnyListener)

Similar to above, if these filters aren't working it would be good to understand why not and if they should be fixed vs. creating a second filtering implementation.

Copy link
Member

@noahfalk noahfalk left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looking better - still some bugs need fixing : )

Copy link
Member

@noahfalk noahfalk left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Still got bugs I'm afraid


internal bool IsEventEnabled(EventLevel level, EventKeywords keywords)
{
if (level == EventLevel.LogAlways || keywords == 0 || m_Keywords == 0)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logic still has some trouble. One example would be m_level =Informational, m_keywords=0x0, level = verbose, keywords=0x0. Expected result: false (listener level is too low), Actual result: true.

You probably should be calling EventSource.IsEnabledCommon() except reviewing that code it also appears to have bugs here and here : (. EventPipe native code has a correct implementation though the special case in the levelEnabled check for LogAlways is unnecessary complexity. LogAlways is the lowest value so sessionLevel >= LogAlways is always true.

The fact that we've got all these all these filtering bugs lurking probably means we are in need of EventListener level/keyword filtering tests for both the self-describing case and the manifested events.

I think you could fix IsEnabledCommon() to look like this:

        private static bool IsEnabledCommon(bool enabled, EventLevel currentLevel, EventKeywords currentMatchAnyKeyword,
                                                          EventLevel eventLevel, EventKeywords eventKeywords, EventChannel eventChannel)
        {
            if (!enabled)
                return false;

            // does is pass the level test?
            if (currentLevel < eventLevel)
                return false;

            // if yes, does it pass the keywords test?
            if (eventKeywords != 0)
            {
#if FEATURE_MANAGED_ETW_CHANNELS
                // is there a channel with keywords that match currentMatchAnyKeyword?
                if (eventChannel != EventChannel.None && this.m_channelData != null && this.m_channelData.Length > (int)eventChannel)
                {
                    EventKeywords channel_keywords = unchecked((EventKeywords)(m_channelData[(int)eventChannel] | (ulong)eventKeywords));
                    if (channel_keywords != 0 && (channel_keywords & currentMatchAnyKeyword) == 0)
                        return false;
                }
                else
#endif
                {
                    if ((unchecked((ulong)eventKeywords & (ulong)currentMatchAnyKeyword)) == 0)
                        return false;
                }
            }
            return true;
        }

Once you had that you could invoke it with Channel.None to get the right filtering behavior.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I also notice the code in WriteStringToAllListeners() has a suspicious loop over m_EventEnabled[] that tries to infer if the listener is enabled or not. I could imagine that code may also not be doing the right thing for self-describing events? It would worth testing as part of the filtering tests.


// For self-describing events, loop through the dispatchers m_Level and m_Keywords to compute
// the remaining listeners' maximum level and keywords.
if (SelfDescribingEvents)
Copy link
Member

@noahfalk noahfalk Jul 21, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think its legal to create an EventSource using manifested types and then call Write<T>(...) to do one-off serialization of self-describing events. In this case SelfDescribingEvents would be false, but it would still be necessary to track level/keywords.

(If you are curious I only spotted this because the code above that set level and keywords didn't check SelfDescribingEvents and I noticed the invariant wasn't consistent)

@sywhang
Copy link
Contributor Author

sywhang commented Feb 8, 2021

Closing the stale PR and I'll be following up again with a new fix soon :-)

@sywhang sywhang closed this Feb 8, 2021
@ghost ghost locked as resolved and limited conversation to collaborators Mar 10, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

EventCounter events not filtered by EventSource/EventListener relationship

3 participants