Skip to content

More than 99 times of elapsed time on Linux #1434

@pengweiqhca

Description

@pengweiqhca
class Program
{
	static async Task Main(string[] args)
	{
		System.Console.WriteLine("TicksPerSecond: " + TimeSpan.TicksPerSecond);
		System.Console.WriteLine("Frequency: " + Stopwatch.Frequency);

		var a1 = Stopwatch.GetTimestamp();
		await Task.Delay(100);
		var b1 = Stopwatch.GetTimestamp();
		Console.WriteLine($"{a1} - {b1} = {b1 - a1}");
		Console.WriteLine(TimeSpan.FromTicks(b1 - a1).TotalMilliseconds);

		ThreadPool.SetMinThreads(128, 128);

		ConnectionMultiplexer.SetFeatureFlag("preventthreadtheft", true);
		var a = await ConnectionMultiplexer.ConnectAsync("127.0.0.1");
		var db = a.GetDatabase(0);
		db.KeyTimeToLive("abc");
		await db.KeyTimeToLiveAsync("abc");

		var sesstion = new ServiceProfiler().GetSession();
		a.RegisterProfiler(() => sesstion);

		var sw = Stopwatch.StartNew();

		await Task.WhenAll(Enumerable.Range(0, 100)
			.Select(_ => Task.Run(async () =>
			{
				for (var index = 0; index < 100; index++)
				{
					//db.KeyTimeToLive("abc");
					await db.KeyTimeToLiveAsync("abc");
				}
			})));

		Console.WriteLine(sw.ElapsedMilliseconds);

		Console.WriteLine(JsonSerializer.Serialize(sesstion.FinishProfiling()
			.GroupBy(cmd => cmd.Command)
			.ToDictionary(group => group.Key,
				group => (object)new
				{
					Count = group.Count(),
					CreationToEnqueued = group.Average(cmd => cmd.CreationToEnqueued.TotalMilliseconds),
					EnqueuedToSending = group.Average(cmd => cmd.EnqueuedToSending.TotalMilliseconds),
					SentToResponse = group.Average(cmd => cmd.SentToResponse.TotalMilliseconds),
					ResponseToCompletion = group.Average(cmd => cmd.ResponseToCompletion.TotalMilliseconds),
					ElapsedTime = group.Average(cmd => cmd.ElapsedTime.TotalMilliseconds),
				}), new JsonSerializerOptions { WriteIndented = true }));
	}
}

public class ServiceProfiler
{
	private readonly AsyncLocal<ProfilingSession> _contextValue = new AsyncLocal<ProfilingSession>();

	public ProfilingSession GetSession() => _contextValue.Value ?? (_contextValue.Value = new ProfilingSession());
}

Run on windows

TicksPerSecond: 10000000
Frequency: 10000000
5452341015297 - 5452342144938 = 1129641
112.9641
2515
{
  "PTTL": {
    "Count": 10000,
    "CreationToEnqueued": 0.006808230000000094,
    "EnqueuedToSending": 0.03565073000000016,
    "SentToResponse": 24.972403929999956,
    "ResponseToCompletion": 0.0003328800000000343,
    "ElapsedTime": 25.015195770000048
  }
}

Run on Linux

TicksPerSecond: 10000000
Frequency: 1000000000
15477420815300 - 15477523254500 = 102439200
10243.92
3112
{
  "PTTL": {
    "Count": 10000,
    "CreationToEnqueued": 0.7559389999999978,
    "EnqueuedToSending": 16.48761000000003,
    "SentToResponse": 3076.0693229999943,
    "ResponseToCompletion": 0.20282200000001735,
    "ElapsedTime": 3093.5156940000134
  }
}

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions