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 all 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")
{
}

// 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,42 @@ 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("connections-started", this, () => _connectionsStarted)
{
WriteEvent(3, connectionId);
}
DisplayName = "Total Connections Started",
};
_connectionsStoppedCounter ??= new PollingCounter("connections-stopped", this, () => _connectionsStopped)
{
DisplayName = "Total Connections Stopped",
};
_connectionsTimedOutCounter ??= new PollingCounter("connections-timed-out", this, () => _connectionsTimedOut)
{
DisplayName = "Total Connections Timed Out",
};
_currentConnectionsCounter ??= new PollingCounter("current-connections", this, () => _currentConnections)
{
DisplayName = "Current Connections",
};

_connectionDuration ??= new EventCounter("connections-duration", this)
{
DisplayName = "Average Connection Duration",
Copy link
Member

@halter73 halter73 Jun 13, 2019

Choose a reason for hiding this comment

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

If we're renaming anyway, this should probably be called "connections-duration-milliseconds".

If we decide that's too verbose, we should still document the units somewhere. The DisplayName should include "milliseconds" or "ms" somewhere.

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 a new display units field coming

};
}
}

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("c26fe4b6-8790-5d41-5900-0f2b6b74efaa"), 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