Tagc Tagc - 2 months ago 23
C# Question

ASP.NET Core SignalR - browser window remains "loading" for 120 seconds

Background



I'm trying to build an ASP.NET Core web application that requires bidirectional real-time communication between the server and client. I've tried using the ASP.NET Core port of SignalR for this.

Environment





Problem



When I launch the application (
IIS Express
button in VS2015), a new Firefox tab opens at
localhost:...
, rendering my
Views\Home\Index.cshtml
. This works fine and the page seems to be fully loaded within a few seconds, but the "loading" spinning wheel icon persists for about 123 seconds.

From Application Insights, I can see that the browser makes a GET request for "Home/Index" and "/signalr/hubs" immediately, followed by a 120 second pause before further signalr requests are made:

Comms test application insights

At about the same time as these last three events, I see the following logs appear in Firefox's debugger:



[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: Client subscribed to hub 'communicationshub'.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: Negotiating with '/signalr/negotiate?clientProtocol=1.5&connectionData=%5B%7B%22name%22%3A%22communicationshub%22%7D%5D'.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: longPolling transport starting.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: Opening long polling request to 'http://localhost:61192/signalr/connect?transport=longPolling&clientProtocol=1.5&connectionToken=CfDJ8POyhc9yf1ZCtsJ9aOnflZgBHgcMoU0sLdQxkrNhkMLtIP%2BGWCL%2BPNY5H1RhK%2Fl92vibhhTu1PQxPpkcg%2BhpFwYw%2BNyFcTNplZ2HPBXd4QVZVOlP7QR9eIkuoCIDZMFedKEk7kzC7cXBhoF8838KJEAZnGz%2BqQGlePSxmoM6WVhW&connectionData=%5B%7B%22name%22%3A%22communicationshub%22%7D%5D'.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: Long poll complete.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: LongPolling connected.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: longPolling transport connected. Initiating start request.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: Opening long polling request to 'http://localhost:61192/signalr/poll?transport=longPolling&clientProtocol=1.5&connectionToken=CfDJ8POyhc9yf1ZCtsJ9aOnflZgBHgcMoU0sLdQxkrNhkMLtIP%2BGWCL%2BPNY5H1RhK%2Fl92vibhhTu1PQxPpkcg%2BhpFwYw%2BNyFcTNplZ2HPBXd4QVZVOlP7QR9eIkuoCIDZMFedKEk7kzC7cXBhoF8838KJEAZnGz%2BqQGlePSxmoM6WVhW&connectionData=%5B%7B%22name%22%3A%22communicationshub%22%7D%5D'.jquery.signalR-2.2.1.js:82:17
[11:37:43 GMT+0100 (GMT Standard Time)] SignalR: The start request succeeded. Transitioning to the connected state.jquery.signalR-2.2.1.js:82:17
Connected. connectionId : 9d6591af-f1b1-403f-bc42-c81a1b33b25clocalhost:61192:79:21
[11:39:34 GMT+0100 (GMT Standard Time)] SignalR: Long poll complete.jquery.signalR-2.2.1.js:82:17
[11:39:34 GMT+0100 (GMT Standard Time)] SignalR: Opening long polling request to 'http://localhost:61192/signalr/poll?transport=longPolling&clientProtocol=1.5&connectionToken=CfDJ8POyhc9yf1ZCtsJ9aOnflZgBHgcMoU0sLdQxkrNhkMLtIP%2BGWCL%2BPNY5H1RhK%2Fl92vibhhTu1PQxPpkcg%2BhpFwYw%2BNyFcTNplZ2HPBXd4QVZVOlP7QR9eIkuoCIDZMFedKEk7kzC7cXBhoF8838KJEAZnGz%2BqQGlePSxmoM6WVhW&connectionData=%5B%7B%22name%22%3A%22communicationshub%22%7D%5D'.


My questions are:


  • Why is it taking so long to establish a connection?

  • How can I eliminate this delay so that all this happens immediately, instead of after 123 seconds?



Further Details



Startup - ConfigureServices:

public void ConfigureServices(IServiceCollection services)
{
// Add framework services.
services.AddApplicationInsightsTelemetry(Configuration);
services.AddMvc();

services.AddSignalR(options =>
{
options.Hubs.EnableDetailedErrors = true;
});

services.AddSingleton<CommunicationsHub>();
services.AddScoped<ICommunicationsManager, CommunicationsManager>();
}


Startup - Configure:

public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
{
loggerFactory.AddConsole(Configuration.GetSection("Logging"));
loggerFactory.AddDebug();

app.UseApplicationInsightsRequestTelemetry();

if (env.IsDevelopment())
{
app.UseDeveloperExceptionPage();
app.UseBrowserLink();
}
else
{
app.UseExceptionHandler("/Home/Error");
}

app.UseApplicationInsightsExceptionTelemetry();

app.UseStaticFiles();
app.UseWebSockets();
app.UseSignalR();

app.UseMvc(routes =>
{
routes.MapRoute(
name: "default",
template: "{controller=Home}/{action=Index}/{id?}");
});
}


CommunicationsHub:

public class CommunicationsHub : Hub
{
public class TransmissionRequestedEventArgs : EventArgs
{
public TransmissionRequestedEventArgs(GenericMessage message)
{
this.Message = message;
}

public GenericMessage Message { get; }
}

private readonly IHubContext context;

public CommunicationsHub(IConnectionManager connectionManager)
{
this.context = connectionManager.GetHubContext<CommunicationsHub>();
}

public event EventHandler<TransmissionRequestedEventArgs> MessageTransmissionRequested;

public void OnMessageReceived(GenericMessage message)
{
context.Clients.All.onMessageReceived(message);
}

public void SendMessage(GenericMessage message)
{
MessageTransmissionRequested?.Invoke(this, new TransmissionRequestedEventArgs(message));
context.Clients.All.onMessageSent(message);
}
}


Index.cshtml:

@using <<Company>>.Communications.Core
@model IEnumerable<ICommunicationService>
@{
ViewData["Title"] = "Home Page";
}

@section scripts
{
<script src="../Scripts/jquery.signalR-2.2.1.js"></script>
<script src="../signalr/hubs"></script>
<script>
$(function () {
var $tbl = $("#data");
var comms = $.connection.communicationsHub;
comms.client.onMessageReceived = function (message) {
console.log("Message received: " + message)
};
comms.client.onMessageSent = function (message) {
console.log("Message sent: " + message)
};

$.connection.hub.logging = true;
console.log($.connection.hub.logging);
$.connection.hub.start({ transport: 'longPolling' })
.done(function () {
console.log('Connected. connectionId : ' + $.connection.hub.id);
})
.fail(function () {
console.log('Could not connect!');
});
});
</script>
}

Please select a communications service to test:
<ul class="nav nav-pills nav-stacked">
@foreach (var controller in Model)
{
<li role="presentation">
<span class="glyphicon glyphicon-star" aria-hidden="true"></span>@controller
</li>
}
</ul>

<table id="data"></table>


Update 1

It turns out this has nothing to do with SignalR - my fault.

Oddly, I found that my "Index" view still took a very long time to load even after moving all the SignalR logic to another view. I went backwards through my VCS history until I found the commit where the problem was introduced and tracked down the root of the problem. My
HomeController
class is injected with an instance of
ICommunicationManager
during construction, which will cause my
CommunicationManager
to be instantiated. This is the constructor for
CommunicationManager
:

public CommunicationsManager()
{
var assemblies = from name in DependencyContext.Default.GetDefaultAssemblyNames()
where name.Name.StartsWith("<<Company Name>>")
select Assembly.Load(name);

var configuration = new ContainerConfiguration()
.WithAssemblies(assemblies);

var container = configuration.CreateContainer();
this.Candidates = container.GetExports<ICommunicationService>();
}


If I get rid of this logic and set
this.Candidates
to an empty list, the page loads fine without the 120+ second spinning wheel. Weirdly, the code itself executes pretty quickly and the page loads with all the expected exports.

I'll try to figure out why this is happening and after that I'll close the question. Any help would still be appreciated.

Update 2

I've got a much better understanding of the root of the problem now.
ICommunicationManager
(indirectly) inherits
IDisposable
. I implement the disposal pattern in
CommunicationManager
:

#region IDisposable Support
private bool disposedValue = false; // To detect redundant calls

protected virtual void Dispose(bool disposing)
{
if (!disposedValue)
{
if (disposing)
{
this.Candidates.ToList().ForEach(it => it.Dispose());
}
disposedValue = true;
}
}

// This code added to correctly implement the disposable pattern.
public void Dispose()
{
// Do not change this code. Put cleanup code in Dispose(bool disposing) above.
Dispose(true);
}
#endregion


By breakpointing this code, I've found that something (the ASP.NET framework I assume) is trying to dispose the communication manager shortly after returning the "Index" view even though
HomeController
maintains a reference to it as one of its private fields. By adding a
return
statement right at the start of
Dispose
(to prevent actually disposing anything), I find that the loading issue disappears.

How can I prevent the ASP.NET framework (or whatever it is) from automatically disposing
CommunicationManager
? I'd like to only dispose it when the web service is shutdown.

Update 3

I've decided I didn't actually need
ICommunicationManager
to implement
ICommunicationService
, in which case I can dump disposal support. That means my application is now working properly. However, I'd still appreciate any information about why
ICommunicationManager.Dispose()
was automatically being closed - I couldn't find anything myself from a cursory search.

Answer

Your CommunicationsManager is being disposed because you registered it with AddScoped. Scoped lifetime services are created once per request and they are disposed at the end of the scope (i.e. request).