Skip to content

Convert SignalR EventSource usage to new pattern #11130

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 6 commits into from
Jun 14, 2019
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 1 addition & 23 deletions src/Hosting/Hosting/test/Internal/HostingEventSourceTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
using System.Threading.Channels;
using System.Threading.Tasks;
using Microsoft.AspNetCore.Http;
using Microsoft.AspNetCore.Internal;
using Microsoft.AspNetCore.Testing;
using Microsoft.AspNetCore.Testing.xunit;
using Xunit;
Expand Down Expand Up @@ -241,29 +242,6 @@ private static HostingEventSource GetHostingEventSource()
return new HostingEventSource(Guid.NewGuid().ToString());
}

private class TestEventListener : EventListener
{
private readonly int _eventId;

public TestEventListener(int eventId)
{
_eventId = eventId;
}

public EventWrittenEventArgs EventData { get; private set; }

protected override void OnEventWritten(EventWrittenEventArgs eventData)
{
// The tests here run in parallel and since the single publisher instance (HostingEventingSource)
// notifies all listener instances in these tests, capture the EventData that a test is explicitly
// looking for and not give back other tests' data.
if (eventData.EventId == _eventId)
{
EventData = eventData;
}
}
}

private class CounterListener : EventListener
{
private readonly Dictionary<string, Channel<double>> _counters = new Dictionary<string, Channel<double>>();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@

<ItemGroup>
<Compile Include="$(SharedSourceRoot)test\SkipOnHelixAttribute.cs" />
<Compile Include="$(SharedSourceRoot)EventSource.Testing\TestEventListener.cs" />
<Content Include="testroot\**\*" CopyToOutputDirectory="PreserveNewest" CopyToPublishDirectory="PreserveNewest" />
<Content Include="Microsoft.AspNetCore.Hosting.StaticWebAssets.xml" CopyToOutputDirectory="PreserveNewest" />
</ItemGroup>
Expand Down
29 changes: 29 additions & 0 deletions src/Shared/EventSource.Testing/TestEventListener.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.

using System.Diagnostics.Tracing;

namespace Microsoft.AspNetCore.Internal
{
internal class TestEventListener : EventListener
{
private readonly int _eventId;

public TestEventListener(int eventId)
{
_eventId = eventId;
}

public EventWrittenEventArgs EventData { get; private set; }

protected override void OnEventWritten(EventWrittenEventArgs eventData)
{
// The tests here run in parallel, capture the EventData that a test is explicitly
// looking for and not give back other tests' data.
if (eventData.EventId == _eventId)
{
EventData = eventData;
}
}
}
}
Original file line number Diff line number Diff line change
@@ -1,40 +1,50 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.

using System;
using System.Diagnostics.Tracing;
using System.Threading;
using Microsoft.Extensions.Internal;

namespace Microsoft.AspNetCore.Http.Connections.Internal
{
[EventSource(Name = "Microsoft-AspNetCore-Http-Connections")]
internal class HttpConnectionsEventSource : EventSource
{
public static readonly HttpConnectionsEventSource Log = new HttpConnectionsEventSource();

private readonly EventCounter _connectionsStarted;
private readonly EventCounter _connectionsStopped;
private readonly EventCounter _connectionsTimedOut;
private readonly EventCounter _connectionDuration;
private PollingCounter _connectionsStartedCounter;
private PollingCounter _connectionsStoppedCounter;
private PollingCounter _connectionsTimedOutCounter;
private PollingCounter _currentConnectionsCounter;
private EventCounter _connectionDuration;

private HttpConnectionsEventSource()
private long _connectionsStarted;
private long _connectionsStopped;
private long _connectionsTimedOut;
private long _currentConnections;

internal HttpConnectionsEventSource()
: base("Microsoft-AspNetCore-Http-Connections")
Copy link
Member

Choose a reason for hiding this comment

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

Rename to Microsoft.AspNetCore.Http.Connections?

Copy link
Member Author

Choose a reason for hiding this comment

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

Should we also normalize the counter names? The hosting ones follow the pattern of "current-requests", and we currently use "CurrentConnections".

Copy link
Member

Choose a reason for hiding this comment

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

Yes, lets unify the patterns.

Copy link
Contributor

@analogrelay analogrelay Jun 13, 2019

Choose a reason for hiding this comment

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

EventSource names have always been Microsoft-Things-Separated-By-Dashes, why would we change that?

Also, we should update the hosting ones since these have already shipped with these names. Plus snake-case is so un-.NET ;)

Copy link
Member

Choose a reason for hiding this comment

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

Copy link
Contributor

@analogrelay analogrelay Jun 13, 2019

Choose a reason for hiding this comment

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

Well, it's unfortunate that corefx didn't follow our completely undocumented design pattern from 2.2 here 😝. Hard to fix corefx now though. I'm OK with establishing snake-case as the convention if that's the case.

If we do that we have two options:

  • Leave the SignalR counters alone. Nobody is "broken" but they look different (though the Display Name is what is generally shown I believe)
  • Change the existing SignalR counters to match the new pattern. Anybody depending on the exact name is broken. There weren't great tools for collecting these before 3.0 though so I don't feel too bad breaking that (as long as we Announcements it)

Copy link
Member

Choose a reason for hiding this comment

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

There's only one option, use the new pattern.

{
}

// Used for testing
internal HttpConnectionsEventSource(string eventSourceName)
: base(eventSourceName)
{
_connectionsStarted = new EventCounter("ConnectionsStarted", this);
_connectionsStopped = new EventCounter("ConnectionsStopped", this);
_connectionsTimedOut = new EventCounter("ConnectionsTimedOut", this);
_connectionDuration = new EventCounter("ConnectionDuration", this);
}

// This has to go through NonEvent because only Primitive types are allowed
// in function parameters for Events
[NonEvent]
public void ConnectionStop(string connectionId, ValueStopwatch timer)
{
Interlocked.Increment(ref _connectionsStopped);
Interlocked.Decrement(ref _currentConnections);

if (IsEnabled())
{
var duration = timer.IsActive ? timer.GetElapsedTime().TotalMilliseconds : 0.0;
_connectionDuration.WriteMetric((float)duration);
_connectionsStopped.WriteMetric(1.0f);
_connectionDuration.WriteMetric(duration);

if (IsEnabled(EventLevel.Informational, EventKeywords.None))
{
Expand All @@ -46,15 +56,13 @@ public void ConnectionStop(string connectionId, ValueStopwatch timer)
[Event(eventId: 1, Level = EventLevel.Informational, Message = "Started connection '{0}'.")]
public ValueStopwatch ConnectionStart(string connectionId)
{
if (IsEnabled())
{
_connectionsStarted.WriteMetric(1.0f);
Interlocked.Increment(ref _connectionsStarted);
Interlocked.Increment(ref _currentConnections);

if (IsEnabled(EventLevel.Informational, EventKeywords.None))
{
WriteEvent(1, connectionId);
return ValueStopwatch.StartNew();
}
if (IsEnabled(EventLevel.Informational, EventKeywords.None))
{
WriteEvent(1, connectionId);
return ValueStopwatch.StartNew();
}
return default;
}
Expand All @@ -65,14 +73,39 @@ public ValueStopwatch ConnectionStart(string connectionId)
[Event(eventId: 3, Level = EventLevel.Informational, Message = "Connection '{0}' timed out.")]
public void ConnectionTimedOut(string connectionId)
{
if (IsEnabled())
Interlocked.Increment(ref _connectionsTimedOut);

if (IsEnabled(EventLevel.Informational, EventKeywords.None))
{
_connectionsTimedOut.WriteMetric(1.0f);
WriteEvent(3, connectionId);
}
}

if (IsEnabled(EventLevel.Informational, EventKeywords.None))
protected override void OnEventCommand(EventCommandEventArgs command)
{
if (command.Command == EventCommand.Enable)
{
// This is the convention for initializing counters in the RuntimeEventSource (lazily on the first enable command).
// They aren't disabled afterwards...

_connectionsStartedCounter ??= new PollingCounter("ConnectionsStarted", this, () => _connectionsStarted)
{
WriteEvent(3, connectionId);
}
DisplayName = "Total Connections Started",
};
_connectionsStoppedCounter ??= new PollingCounter("ConnectionsStopped", this, () => _connectionsStopped)
{
DisplayName = "Total Connections Stopped",
};
_connectionsTimedOutCounter ??= new PollingCounter("ConnectionsTimedOut", this, () => _connectionsTimedOut)
{
DisplayName = "Total Connections Timed Out",
};
_currentConnectionsCounter ??= new PollingCounter("CurrentConnections", this, () => _currentConnections)
{
DisplayName = "Current Connections",
};

_connectionDuration ??= new EventCounter("ConnectionDuration", this);
}
}

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,112 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.

using System;
using System.Diagnostics.Tracing;
using Microsoft.AspNetCore.Internal;
using Microsoft.Extensions.Internal;
using Xunit;

namespace Microsoft.AspNetCore.Http.Connections.Internal
{
public class HttpConnectionsEventSourceTests
{
[Fact]
public void MatchesNameAndGuid()
{
// Arrange & Act
var eventSource = new HttpConnectionsEventSource();

// Assert
Assert.Equal("Microsoft-AspNetCore-Http-Connections", eventSource.Name);
Assert.Equal(Guid.Parse("a81dd8b5-9721-5e7a-d465-d5b9caa864dc"), eventSource.Guid);
}

[Fact]
public void ConnectionStart()
{
// Arrange
var expectedEventId = 1;
var eventListener = new TestEventListener(expectedEventId);
var httpConnectionsEventSource = GetHttpConnectionEventSource();
eventListener.EnableEvents(httpConnectionsEventSource, EventLevel.Informational);

// Act
httpConnectionsEventSource.ConnectionStart("1");

// Assert
var eventData = eventListener.EventData;
Assert.NotNull(eventData);
Assert.Equal(expectedEventId, eventData.EventId);
Assert.Equal("ConnectionStart", eventData.EventName);
Assert.Equal(EventLevel.Informational, eventData.Level);
Assert.Same(httpConnectionsEventSource, eventData.EventSource);
Assert.Equal("Started connection '{0}'.", eventData.Message);
Assert.Collection(eventData.Payload,
arg =>
{
Assert.Equal("1", arg);
});
}

[Fact]
public void ConnectionStop()
{
// Arrange
var expectedEventId = 2;
var eventListener = new TestEventListener(expectedEventId);
var httpConnectionsEventSource = GetHttpConnectionEventSource();
eventListener.EnableEvents(httpConnectionsEventSource, EventLevel.Informational);

// Act
var stopWatch = ValueStopwatch.StartNew();
httpConnectionsEventSource.ConnectionStop("1", stopWatch);

// Assert
var eventData = eventListener.EventData;
Assert.NotNull(eventData);
Assert.Equal(expectedEventId, eventData.EventId);
Assert.Equal("ConnectionStop", eventData.EventName);
Assert.Equal(EventLevel.Informational, eventData.Level);
Assert.Same(httpConnectionsEventSource, eventData.EventSource);
Assert.Equal("Stopped connection '{0}'.", eventData.Message);
Assert.Collection(eventData.Payload,
arg =>
{
Assert.Equal("1", arg);
});
}

[Fact]
public void ConnectionTimedOut()
{
// Arrange
var expectedEventId = 3;
var eventListener = new TestEventListener(expectedEventId);
var httpConnectionsEventSource = GetHttpConnectionEventSource();
eventListener.EnableEvents(httpConnectionsEventSource, EventLevel.Informational);

// Act
httpConnectionsEventSource.ConnectionTimedOut("1");

// Assert
var eventData = eventListener.EventData;
Assert.NotNull(eventData);
Assert.Equal(expectedEventId, eventData.EventId);
Assert.Equal("ConnectionTimedOut", eventData.EventName);
Assert.Equal(EventLevel.Informational, eventData.Level);
Assert.Same(httpConnectionsEventSource, eventData.EventSource);
Assert.Equal("Connection '{0}' timed out.", eventData.Message);
Assert.Collection(eventData.Payload,
arg =>
{
Assert.Equal("1", arg);
});
}

private static HttpConnectionsEventSource GetHttpConnectionEventSource()
{
return new HttpConnectionsEventSource(Guid.NewGuid().ToString());
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
<ItemGroup>
<Compile Include="$(SharedSourceRoot)Buffers.Testing\**\*.cs" />
<Compile Include="$(SharedSourceRoot)SyncPoint\SyncPoint.cs" />
<Compile Include="$(SharedSourceRoot)EventSource.Testing\TestEventListener.cs" />
</ItemGroup>

<ItemGroup>
Expand Down