15. Диагностика async-кода¶

// Глава 15. Зависшее приложение: найдите причину снаружи.
// Запуск: dotnet run -c Release --project start
// PREDICT: что покажет dotnet-stack для потока "UI"? Хватит ли его, чтобы понять, кого этот поток ждёт?
// TODO 1: пока программа «висит», выполните dotnet tool run dotnet-stack report -p <PID> (PID печатается).
// TODO 2: снимите дамп (dotnet-dump collect) и найдите в dumpasync машину состояний в состоянии 0, ждущую уже завершённую задачу.
using System.Collections.Concurrent;

var ui = new SingleThreadContext();
ui.Post(_ =>
{
    Console.WriteLine("[UI] обработчик начал");
    string result = LoadReportAsync("sales").Result;          // блокируем единственный поток контекста
    Console.WriteLine($"[UI] обработчик закончил: {result}");   // сюда не дойдём
}, null);
Console.WriteLine($"PID {Environment.ProcessId}. Приложение «зависло»; завершится через 120 с.");
Thread.Sleep(TimeSpan.FromSeconds(120));

static async Task<string> LoadReportAsync(string name)
{
    string raw = await FetchAsync(name);    // продолжение обязано вернуться в UI-контекст
    return raw.ToUpperInvariant();
}

static async Task<string> FetchAsync(string name)
{
    await Task.Delay(100);
    return $"отчёт {name}";
}

sealed class SingleThreadContext : SynchronizationContext
{
    private readonly BlockingCollection<(SendOrPostCallback, object?)> _queue = new();
    public SingleThreadContext()
    {
        new Thread(() =>
        {
            SetSynchronizationContext(this);
            foreach (var (cb, state) in _queue.GetConsumingEnumerable()) cb(state);
        }) { Name = "UI", IsBackground = true }.Start();
    }
    public override void Post(SendOrPostCallback d, object? state) => _queue.Add((d, state));
}

// Глава 15. Разбор зависшего async-кода снаружи и изнутри.
//   dotnet run -c Release --project final -- deadlock [секунд]   — дедлок sync-over-async на «UI»-контексте
//   dotnet run -c Release --project final -- starve   [секунд]   — голодание пула потоков
//   dotnet run -c Release --project final -- events   [секунд]   — то же голодание, но с EventListener и счётчиками внутри процесса
// Пока программа «висит», подключайтесь инструментами: см. §15.2–15.5.
int seconds = args.Length > 1 ? int.Parse(args[1]) : 120;
switch (args.FirstOrDefault() ?? "deadlock")
{
    case "deadlock": Hangs.Deadlock(seconds); break;
    case "starve": await Hangs.Starvation(seconds); break;
    case "events": await Inside.RunAsync(seconds); break;
}

using System.Collections.Concurrent;
using System.Diagnostics;

// Два «зависания», которые мы потом разбираем снаружи инструментами.
static class Hangs
{
    // ---- 1. Дедлок: sync-over-async на однопоточном SynchronizationContext (глава 6) ----
    public static void Deadlock(int seconds)
    {
        var ui = new SingleThreadContext();
        ui.Post(_ =>
        {
            Console.WriteLine("[UI] обработчик начал");
            string result = LoadReportAsync("sales").Result;   // блокируем единственный поток контекста
            Console.WriteLine($"[UI] обработчик закончил: {result}");  // сюда не дойдём
        }, null);
        Console.WriteLine($"PID {Environment.ProcessId}. Приложение «зависло»; само завершится через {seconds} с.");
        Thread.Sleep(TimeSpan.FromSeconds(seconds));
    }

    static async Task<string> LoadReportAsync(string name)
    {
        string raw = await FetchAsync(name);       // продолжение обязано вернуться в UI-контекст
        return raw.ToUpperInvariant();
    }

    static async Task<string> FetchAsync(string name)
    {
        await Task.Delay(100);                     // ждём «сеть»
        return $"отчёт {name}";
    }

    // ---- 2. Голодание пула потоков: блокирующие обработчики + «проба задержки» (глава 13) ----
    public static async Task Starvation(int seconds)
    {
        ThreadPool.SetMinThreads(4, 4);
        Console.WriteLine($"PID {Environment.ProcessId}. Нагрузка из блокирующих обработчиков; завершится через {seconds} с.");
        var end = Stopwatch.StartNew();

        _ = Task.Run(async () =>                   // «входящие запросы»: по 20 штук в секунду
        {
            while (end.Elapsed.TotalSeconds < seconds)
            {
                for (int i = 0; i < 20; i++) ThreadPool.QueueUserWorkItem(_ => Handler());
                await Task.Delay(1000);
            }
        });

        while (end.Elapsed.TotalSeconds < seconds)  // проба: сколько ждёт самая простая работа в очереди пула
        {
            long queued = Stopwatch.GetTimestamp();
            var tcs = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
            ThreadPool.QueueUserWorkItem(_ => tcs.SetResult());
            await tcs.Task;
            Console.WriteLine($"  t={end.Elapsed.TotalSeconds,4:F1}с  задержка пула {Stopwatch.GetElapsedTime(queued).TotalMilliseconds,6:F0} мс  потоков {ThreadPool.ThreadCount,3}  в очереди {ThreadPool.PendingWorkItemCount,4}");
            await Task.Delay(1000);
        }
    }

    static void Handler() => Thread.Sleep(3000);   // «синхронный вызов БД» внутри обработчика

    sealed class SingleThreadContext : SynchronizationContext
    {
        private readonly BlockingCollection<(SendOrPostCallback, object?)> _queue = new();
        public SingleThreadContext()
        {
            new Thread(() =>
            {
                SetSynchronizationContext(this);
                foreach (var (cb, state) in _queue.GetConsumingEnumerable()) cb(state);
            }) { Name = "UI", IsBackground = true }.Start();
        }
        public override void Post(SendOrPostCallback d, object? state) => _queue.Add((d, state));
    }
}

using System.Collections.Concurrent;
using System.Diagnostics.Metrics;
using System.Diagnostics.Tracing;

// То же голодание, но диагностика встроена в процесс: события рантайма и встроенные счётчики.
static class Inside
{
    public static async Task RunAsync(int seconds)
    {
        using var events = new PoolEventListener();
        using var meters = StartMeters();

        await Hangs.Starvation(seconds);

        Console.WriteLine();
        Console.WriteLine("События пула за время работы:");
        foreach (var line in events.Summary()) Console.WriteLine("  " + line);
    }

    static MeterListener StartMeters()
    {
        var listener = new MeterListener();
        listener.InstrumentPublished = (instrument, l) =>
        {
            if (instrument.Meter.Name == "System.Runtime" && instrument.Name.StartsWith("dotnet.thread_pool"))
                l.EnableMeasurementEvents(instrument);
        };
        listener.SetMeasurementEventCallback<long>((inst, value, tags, state) =>
            Console.WriteLine($"    [метрика] {inst.Name} = {value}"));
        listener.SetMeasurementEventCallback<int>((inst, value, tags, state) =>
            Console.WriteLine($"    [метрика] {inst.Name} = {value}"));
        listener.Start();
        _ = Task.Run(async () =>                   // метрики-«наблюдатели» читаются по запросу
        {
            while (true) { await Task.Delay(5000); listener.RecordObservableInstruments(); }
        });
        return listener;
    }

    sealed class PoolEventListener : EventListener
    {
        private readonly ConcurrentDictionary<string, int> _counts = new();
        private readonly ConcurrentQueue<string> _adjustments = new();

        protected override void OnEventSourceCreated(EventSource source)
        {
            if (source.Name == "Microsoft-Windows-DotNETRuntime")
                EnableEvents(source, EventLevel.Informational, (EventKeywords)0x10000);   // ThreadingKeyword
        }

        protected override void OnEventWritten(EventWrittenEventArgs e)
        {
            _counts.AddOrUpdate(e.EventName ?? $"#{e.EventId}", 1, (_, n) => n + 1);
            if (e.EventName is not null && e.EventName.StartsWith("ThreadPoolWorkerThreadAdjustment") && e.Payload is not null)
                _adjustments.Enqueue(e.EventName + ": " + string.Join(", ", e.PayloadNames!.Zip(e.Payload, (n, v) => $"{n}={v}")));
        }

        public IEnumerable<string> Summary()
        {
            foreach (var kv in _counts.OrderByDescending(kv => kv.Value)) yield return $"{kv.Key,-50} {kv.Value}";
            yield return "--- первые события подстройки пула ---";
            foreach (var a in _adjustments.Take(12)) yield return a;
        }
    }
}