Feedback

[tpeczek]

This issue is for general feedback regarding this project.

[bjsafdie]

It would be great if you updated your blog or added new documentation to reflect the current state of the code.

[AcidRaZor]

Would be nice to have implementation documentation. I appreciate the documentation explains how this Nuget works, but it doesn't really give an example of how to implement.

I've added it to my project, added "services.AddServerTiming();" to my "ConfigureServices" and use the DI to then capture a task timing: "_serverTiming.TimeTask"

But no headers are output with the timing.

[bjsafdie]

Agreed. I have similar issues. I set up everything, including the middleware in Startup. I can time events in my service and the Metrics collection on the service is populated. I verified this in the controller after the service call by examining ((IServerTiming)_myService).Metrics. However, the middleware does not seem to add the metrics to the HTTP response headers. One other thing is that the current DI setup requires a one-to-one mapping from IServerTiming to a single service. I was hoping to implement IServerTiming at the service layer to capture overall time on service calls, but also at the data access layer to allow DB operation or external API call timings to be captured closest to the data access code.

[tpeczek]

Hi @AcidRaZor, @bjsafdie

Yes, I must admit that I've dropped the ball when it comes to documentation on this one.

What I could do quickly was adding the most basic demo possible, which just shows how to wire things up so something works - it's there now.

I'll try to carve out some time to create decent docs as soon as possible.

Meanwhile, if you share some details on your scenarios, I can try to help.

[bjsafdie]

@tpeczek That demo is welcome, but it uses the same hard-coded metric in the response as your blog entry.

My scenario is pretty much as I outlined above.

1. I registered IServerTiming as a scoped service that resolves to my concrete service class.
2. I configured the app to UseServerTiming.
3. I implemented IServerTiming in my service and capture metrics.
4. I am not setting any origin headings.

I confirm (via a debugging breakpoint) that ((IServerTiming)_myService).Metrics has a Count greater than zero and contains entries after it returns to the controller.

When the middleware fired and entered HandleServerTimingAsResponseHeaderAsync, I was able to confirm that the injected serverTiming is an instance of my service class, but serverTiming.Metrics.Count is zero, so no headers are added. I do not know what is happening unless my service is somehow considered out of scope when the middleware fires and thus it is injected with a new, empty instance. That doesn't seem right, but it would explain the empty Metrics collection in the middleware.

I do not know if this is relevant, but the middleware executes a couple of times before my controller action fires, and then once afterward (as one would expect). I have not debugged middleware before so I do not know if this is expected behavior.

[tpeczek]

@bjsafdie

My quick guess is that you are hitting HTTP/1.1 limitation - only metrics captured before response headers had been send can be send. In HTTP/2 timings can be send in trailer headers which creates a lot more usable scenarios. You can read more here: https://www.tpeczek.com/2020/09/little-known-aspnet-core-features-http.html

[AcidRaZor]

Thanks @tpeczek , I actually was able to ascertain from your original writeup what the basic "this is how to get it going" was.

My issue is that when adding it as a DI, sending it through to a controller, using _service.Task( ... run await task here ... , "metric name");

Nothing is output. I would imagine this can't be an HTTP 1.1 limitation just outputting a response? Because the metrics will be calculated before any response is given, so no need to rely on http/2 for trailer headers.... unless this is how your nuget package works (and I can't see it documented anywhere that http/2 is required for this to work?)

[tpeczek]

Hi @AcidRaZor,

In fact sending an HTTP/1.1 response in an efficient manner (which ASP.NET Core focuses on doing as much as possible) is quite complicated under the hood. As a result the response headers are often send quite early in comparison to response body. It's quite common for headers to be send while you controller is still working on the body.

My implementation can work with both HTTP/1.1 and HTTP/2, but there are significant differences in time window you have for capturing the metrics - this what the post I've provided above describes.

Of course there might be something else happening, but in general the usage of this library boils down to those basic "this is how to get it going":

• Register service
• Register middleware
• Get an instance of the service from DI in context of a request and add metrics

I'm using this quite heavily and the only weird behavior I've observed so far was due to ASP.NET Core pushing out the response headers at different time than I was expecting.

I see no problem in reviewing your case in details if you provide some repro code.

[bjsafdie]

@tpeczek Thanks for being so responsive. I see the issue with the HTTP versions, even if I am not sure how to solve it. But how would that explain that the serverTiming.Metrics.Count is zero in the middleware context.Response.OnStarting anonymous function? I get that any headers written might not be sent because of the timing, but I am still unclear as to why that would cause the injected IServerTimings to have none of the metrics entries that were recorded and demonstrably visible in the controller.

[tpeczek]

@bjsafdie Hard to say. It might be a result of observing two different contexts due to nature of middlewares, or it might be something completely else.

At this point I'm down to speculation. To be able to say something for sure, O would have to put my hands on some kind of repro, if you can share one.

[AcidRaZor]

Thanks @tpeczek. My repo is unfortunately private, but I'll try and whip up a similar case and share.

We have OAuth to Graph API (Sharepoint) with a few other things. One of which is an ETag filter middleware that results in a 304 if no data has been modified since last ETag generation. I did take that out to see if it would capture/respond with Server API headers, but no joy.

One thing I did notice is, for compression specifically (gzip/brotli), my AV does seem to act like a middleman, which means I don't get to see the gzipped response on the API, could it be AV affecting this as well?

I did convert to HTTP/2. I'll check again to see if it made a difference.

[tpeczek]

Hi @bjsafdie and @AcidRaZor,

Any updates regarding issues you were facing? Anything I could take a look and debug through to be able to provide some support?

[bjsafdie]

@tpeczek Sadly, I got tired of trying to debug the middleware. I created my own implementation that allows me to collect metrics in any layer (controllers, services, or data access) by injecting a request-scoped service that will accumulate multiple metrics entries. I then use an Action Filter on the controller to append the information to the response headers. The only other requirement is that the controller implements a constructor-injected property to provide access to the metrics collector from the Action Filter context. It is not as complete as your implementation, but it works and I prefer to inject the server timing collector where I need it (and potentially in multiple places) rather than rely on a single class to implement IServerTiming. Nonetheless, your implementation taught me a lot and I thank you for that.

[runxc1]

@bjsafdie did you put that code up anywhere? I just need something very light to time a few things in a specific controller method and was thinking the server timing API might be great for that but haven't really seen any usable C# libraries for timing from a controller method as you mention

[tpeczek]

@runxc1 If you shoot me a sample action you would like to time I can take a stab it.

[bjsafdie]

Since I wrote the code for my employer, I will have to ask for permission before I can post it here. I will get back to you.

[runxc1]

So I did find another .net project that uses the the server timing API with .net core https://github.com/metalface-oss/aspnetcore-servertiming . It allows you to name a timer and start/stop it and was enough for me to test out the one little issue I was having. The project is 3 years old and uses a singleton so doesn't clear out the timings between requests so still a rough project but I feel that it's closer to being usable.

[tpeczek]

Hi @runxc1, @bjsafdie

I'm more than happy to improve this project, but in order to do it I need constructive and actionable feedback.

For example, to achieve equivalent of what is linked above, one can use .TimeAction method. This method starts a timer and returns a disposable object. The timer stops once you dispose the object, this way it also allows for timing blocks of code by wrapping them in using.

[Route("api/[controller]")]
[ApiController]
public class WeatherForecastsController : Controller
{
	...
	
	private readonly IServerTiming _serverTiming;

	public WeatherForecastsController(IServerTiming serverTiming)
	{
		_serverTiming = serverTiming;
	}

	[HttpGet]
	public async Task<IEnumerable<WeatherForecast>> Get()
	{
		List<WeatherForecast> weatherForecasts = new();

		using (_serverTiming.TimeAction())
		{
			for (int daysFromToday = 1; daysFromToday <= 10; daysFromToday++)
			{
				weatherForecasts.Add(await GetWeatherForecastAsync(daysFromToday));
			};
		}

		return weatherForecasts;
	}

	...
}

You can provide name for your timer, but you don't have to and it such case it will figure out the name based on caller attributes - for the above code it sends a metric with name WeatherForecastsController.Get+42.

You can time several separated blocks of code in the same action and there is even a dedicated method to time a Task.

As I said, I'm happy to help but in the end I'm just a dev trying to make mine and others life easier. I have limited bandwidth and need to use it to address specific needs. Maybe it's a specific demo scenario (just pushed the above sample to the repo), maybe it's detailed documentation. I need to understand that, because I can't do everything at once.

So what I'm asking here is please help me in understanding your needs. If I do, I can help. I can't do anything with plain "this sucks".

[runxc1]

@tpeczek that is a great addition and really what I was looking for. If I'd seen something like that in the Readme for this Github I'd have used this project. As for other things I'd expect or want to see in a project like this are.

1. An example of how to only show/collect the Server Timings if I'm running in development or for specific users
2. Nested Calling hierarchy - showing which timings are happening within another timing that was started
3. Documentation on the Github page and not a blog.

[tpeczek]

Thank you @runxc1. I've pushed some docs and restructured the README, I hope it addresses number 3.

Ad. 1 This is an interesting addition, I'll consider some options and create an issue for it.
Ad. 2 I'm interested what would be expectation here. As far as I understand both Server Timing API and browsers rendering for metrics doesn't have any hierarchical capabilities which could be utilized.

[runxc1]

Without browsers supporting it really the only thing I can think of is a naming convention but it may not be worth doing. You could have something like

OuterCallName 500ms
OuterCallName.InnerCallName 250ms
OuterCallName.InnerCallName.EvenFurtherDown 50ms

Not sure if others would use or like that

[tpeczek]

I don't think I would want to enforce naming convention, maybe there is something I can do to make applying it easier. I'll think about it.

[runxc1]

You wouldn't apply a naming convention rather you would know that one timing is happening within another timing.

using (_serverTiming.TimeAction("OuterCallName"))
{
  setup();
  using (_serverTiming.TimeAction("InnerCallName "))
  {
    doSomeWork();
  }
  otherstuff();
}

[tpeczek]

That's interesting, challenging but interesting. I've created following two issues to dig further in the two enhacements you have proposed: #16 and #17.