Logging SignalR Traffic in Server-Side Blazor

Server-Side Blazor is indeed magical due to a hidden communications system keeping a persistent connection between the browser and the server: SignalR. SignalR establishes a circuit for every client and keeps a server-side model of the DOM in memory. The app sends messages when interactions happen in the browser, such as a button click. The server receives those messages and executes whatever code it needs to, such as a button click handler, applies it to the graph, calculates the difference, and sends messages back to the app which updates the DOM. It’s brilliant, really. However, being hidden, it piques our curiosity as to what’s being sent and received.

As I mentioned, this SignalR system is hidden from you as a developer. You can’t just open up the browser tools and watch the traffic. However, with a little tweaking, you can listen in on the conversation and you might be surprised at how little data is being transmitted.

The secret sauce is in how you configure the logging provider and filters. Let me show you how.

Create a new Server-Side Blazor app in Visual Studio 2019 and in the program.cs file change the CreateHostBuilder call to this:

        public static IHostBuilder CreateHostBuilder(string[] args) =>
          Host.CreateDefaultBuilder(args)
             .ConfigureLogging(logging =>
             {
                 logging.ClearProviders();
                 logging.AddConsole();
                 logging.AddFilter(
                   "Microsoft.AspNetCore.SignalR", LogLevel.Trace);
                 logging.AddFilter(
                   "Microsoft.AspNetCore.Http.Connections",
                   LogLevel.Trace);
             })
             .ConfigureWebHostDefaults(webBuilder =>
             {
                 webBuilder.UseStartup<Startup>();
             });

Run the app and open the Output debug window.

Select the application from the Output window’s “Show Output From” dropdown.

As you use the app, you can watch the traffic in the Output window.

Select your application in the Output window’s “Show Output From” dropdown list.

Select your application in the Output window’s “Show Output From” dropdown list.

Let’s take a look at the output. The first thing you see is IIS Express registering the app. No big whoop.

Starting IIS Express ...
Successfully registered URL "http://localhost:50115/" for site "BlazorApp1" application "/"
Successfully registered URL "https://localhost:44389/" for site "BlazorApp1" application "/"
Registration completed for site "BlazorApp1"
IIS Express is running.

Next you see services for json and blazorpack being registered.

dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubProtocolResolver[1]
      Registered SignalR Protocol: json, implemented by Microsoft.AspNetCore.SignalR.Protocol.JsonHubProtocol.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubProtocolResolver[1]
      Registered SignalR Protocol: blazorpack, implemented by Microsoft.AspNetCore.Components.Server.BlazorPack.BlazorPackHubProtocol.

Next you see the hub methods Blazor uses bing bound:

trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'StartCircuit' is bound.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'ConnectCircuit' is bound.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'BeginInvokeDotNetFromJS' is bound.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'EndInvokeJSFromDotNet' is bound.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'DispatchBrowserEvent' is bound.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'OnRenderCompleted' is bound.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[9]
      'ComponentHub' hub method 'OnLocationChanged' is bound.

Next, we see the “heartbeat” being established. If you sit and do nothing, you’ll see the browser “ping” the server to keep the connection alive.

trce: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager[9]
      Starting connection heartbeat.

After a few lines saying that the app has started you see the actual WebSocket being opened with the browser.

dbug: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionManager[1]
      New connection SYQgFSqfV_gwlp9aOtZ-FQ created.
dbug: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher[10]
      Sending negotiation response.
dbug: Microsoft.AspNetCore.Http.Connections.Internal.HttpConnectionDispatcher[4]
      Establishing new connection.
dbug: Microsoft.AspNetCore.SignalR.HubConnectionHandler[5]
      OnConnectedAsync started.
dbug: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[1]
      Socket opened using Sub-Protocol: '(null)'.

Next, a little handshake. I don’t claim to know exactly what’s being said here, but 38 bytes are received using a “hub protocol” defined in blazorpack. Blazorpack is an internal layer that provides access to the hub methods and provides serialization/deserialization services, etc.

trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Text, size: 38, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubProtocolResolver[2]
      Found protocol implementation for requested protocol: blazorpack.
dbug: Microsoft.AspNetCore.SignalR.HubConnectionContext[1]
      Completed connection handshake. Using HubProtocol 'blazorpack'.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[11]
      Sending payload: 3 bytes.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 491, EndOfMessage: True.

Next, the “StartCircuit” method is invoked. It’s a bit of gobbledygook, but this is where things actually get interesting.

dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "0", Target: "StartCircuit", Arguments: [ https://localhost:44389/, https://localhost:44389/, [] ], StreamIds: [  ] }.

Here I’m showing the log entries that were generated when I clicked on the “Fetch Data” page:

trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 353, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "DispatchBrowserEvent", Arguments: [ ,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[11]
      Sending payload: 169 bytes.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "OnLocationChanged", Arguments: [ https://localhost:44389/fetchdata, True ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 27, EndOfMessage: True.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[11]
      Sending payload: 3528 bytes.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[11]
      Sending payload: 133 bytes.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[11]
      Sending payload: 140 bytes.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "OnRenderCompleted", Arguments: [ 7,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 27, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "OnRenderCompleted", Arguments: [ 8,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 27, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "OnRenderCompleted", Arguments: [ 9,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 27, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "OnRenderCompleted", Arguments: [ 10,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.

It looks like the browser is telling Blazor that the mouse was clicked at an X of 106 and a Y of 202. It wraps this in a “DispatchBrowserEvent” message.

Next an “OnLocationChanged” message is sent passing the url https://localhost:44389/fetchdata

That’s a bit different than standard REST traffic, isn’t it? That’s the point of server-side Blazor. It’s not a REST app. All the communication happens via SignalR, even simple navigation. Wow.

Four more messages are sent, which result in “OnRenderCompleted” actions. All in all, about 4K of data is sent, including the weather data itself.

Let’s watch what happens when we click the counter button on the Counter page. To measure this, go to the Counter page, clear the output window, and click the button. Here’s what you see.

trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 292, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "DispatchBrowserEvent", Arguments: [ ,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[11]
      Sending payload: 148 bytes.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.
trce: Microsoft.AspNetCore.Http.Connections.Internal.Transports.WebSocketsTransport[9]
      Message received. Type: Binary, size: 27, EndOfMessage: True.
dbug: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[1]
      Received hub invocation: InvocationMessage { InvocationId: "", Target: "OnRenderCompleted", Arguments: [ 7,  ], StreamIds: [  ] }.
trce: Microsoft.AspNetCore.SignalR.Internal.DefaultHubDispatcher[7]
      InvocationId (null): Sending result of type 'System.Void'.

Not much at all being sent here. I counted about 500 bytes from what I can see in the log.

This stuff is fascinating to me. I don’t pretend to know what exactly is being said, but the conversation is definitely terse.


Carl Franklin

Carl Franklin has been a key leader in the Microsoft developer community since the very early days when he wrote for Visual Basic Programmers Journal. He authored the Q&A column of that magazine as well as many feature articles for VBPJ and other magazines. He has authored two books for John Wiley & Sons on sockets programming in VB, and in 1994 he helped create the very first web site for VB developers, Carl & Gary's VB Home Page.

Carl is a Microsoft MVP for Developer Technologies, and co-host of .NET Rocks!, one of the longest running podcasts ever (2002). Carl is also an accomplished musician and audio/video producer. He started Pwop Studios in 1999 as a record label for his first album, a collaboration with his brother Jay: Strange Communication. Franklin Brothers released Lifeboat To Nowhere in 2011, which has met with rave reviews. In 2013, Carl released his first solo album, Been a While, which features a tune with John Scofield on guitar, as well as an incredible group of musicians local to New London, CT.

Pwop Studios is a full-service audio and video post production studio in New London, CT, where Carl records and produces the podcasts as well as music and video projects - both for himself, Franklin Brothers Band, and the public.