Я не считаю себя специалистом по Go и лишь изредка обращался к этому языку, но хочу поделиться историей об одном баге на стыке Go и ядра Windows, с которым мне «посчастливилось» столкнуться.
Баг до сих пор остаётся актуальным (issue на GitHub), хотя есть основания надеяться, что он будет исправлен в следующем релизе Go.
Тем не менее, если звёзды сойдутся неудачно и ваша программа на Go внезапно зависнет у клиента в вызове CancelIoEx, а воспроизвести и проанализировать проблему не удастся, то, надеюсь, приведённый ниже материал поможет понять её причины и попробовать обойти проблему.
Как проявилась проблема
В реальном сервисе один из потоков под Windows намертво завис в вызове CancelIoEx.
Документация Microsoft утверждает, что CancelIoEx не ожидает завершения отменённых операций:
The CancelIoEx function does not wait for all canceled operations to complete.
Однако на практике поток оставался в состоянии ожидания бесконечно.
Проблема оказалась крайне сложной для воспроизведения. Для её анализа требовался полноценный дамп, но без стабильного сценария воспроизведения это было почти невозможно. Именно это подтолкнуло меня к поиску аномалий, связанных с CancelIoEx. В итоге я наткнулся на загадочные ошибки в тесте Go TestPipeIOCloseRace, issue по которому уже второй год спокойно лежал в backlog. Чтобы облегчить диагностику, я написал небольшой инструмент, основанный на этом тесте.
Hangtest: воспроизводим редкий баг
Чтобы воспроизвести проблему более надёжно, я написал hangtest — небольшое приложение, запускающее несколько воркеров, которые многократно создают пайпы, читают, пишут и закрывают их. По сути, это всё тот же TestPipeIOCloseRace, только в массовом исполнении.
Я решил привести код hangtest целиком, чтобы каждый желающий мог воспроизвести проблему самостоятельно:
package main import ( "errors" "fmt" "io" "os" "runtime" "strings" "sync" "time" ) const ( iterationsPerWorker = 100000 numWorkers = 10 // итого 10_000 итераций параллельно ) func main() { if runtime.GOOS == "js" || runtime.GOOS == "wasip1" { fmt.Printf("skipping on %s: no pipes\n", runtime.GOOS) return } var wg sync.WaitGroup wg.Add(numWorkers) for i := 0; i < numWorkers; i++ { go func(workerID int) { defer wg.Done() for j := 0; j < iterationsPerWorker; j++ { if err := runPipeIOCloseRace(); err != nil { fmt.Printf("worker %d, iteration %d: %v\n", workerID, j, err) } } }(i) } wg.Wait() } func runPipeIOCloseRace() error { r, w, err := Pipe() if err != nil { return fmt.Errorf("pipe creation failed: %w", err) } var wg sync.WaitGroup wg.Add(3) var errOnce sync.Once var firstErr error fail := func(e error) { errOnce.Do(func() { firstErr = e }) } go func() { defer wg.Done() for { n, err := w.Write([]byte("hi")) if err != nil { switch { case errors.Is(err, ErrClosed), strings.Contains(err.Error(), "broken pipe"), strings.Contains(err.Error(), "pipe is being closed"), strings.Contains(err.Error(), "hungup channel"): // Ignore expected errors default: fail(fmt.Errorf("write error: %w", err)) } return } if n != 2 { fail(fmt.Errorf("wrote %d bytes, expected 2", n)) return } } }() go func() { defer wg.Done() var buf [2]byte for { n, err := r.Read(buf[:]) if err != nil { if err != io.EOF && !errors.Is(err, ErrClosed) { fail(fmt.Errorf("read error: %w", err)) } return } if n != 2 { fail(fmt.Errorf("read %d bytes, want 2", n)) } } }() go func() { defer wg.Done() time.Sleep(time.Millisecond) if err := r.Close(); err != nil { fail(fmt.Errorf("close reader: %w", err)) } if err := w.Close(); err != nil { fail(fmt.Errorf("close writer: %w", err)) } }() wg.Wait() return firstErr } // --------- Pipe Implementation (simple wrapper using os.Pipe) --------- // var ErrClosed = errors.New("pipe closed") func Pipe() (*pipeReader, *pipeWriter, error) { r, w, err := os.Pipe() if err != nil { return nil, nil, err } return &pipeReader{r}, &pipeWriter{w}, nil } type pipeReader struct { *os.File } type pipeWriter struct { *os.File }Однако стоит отметить, что даже с таким подходом воспроизвести проблему удалось не сразу. На рабочем ноутбуке с процессором Intel 12‑го поколения зависание так и не проявилось. Первым его удалось поймать на Windows 11 ARM64, а позже — на виртуальной x64‑системе. Это наконец позволило собрать дамп и проанализировать его совместно с поддержкой Microsoft.
Причина зависания
Совместный разбор дампа с поддержкой Microsoft показал следующее:
-
поток №1 выполнял синхронный
ReadFile/WriteFileна пайпе; -
в то же время именно он был инициатором асинхронного I/O, который должен был быть отменён;
-
вызов
CancelIoExиз другого потока помещал в очередь APC для отмены, но доставить его было некому — при синхронном вводе‑выводе ядро Windows отключает доставку обычных kernel APC; -
в результате второй поток также блокировался, ожидая выполнения APC, которое никогда не наступит.
Стоит отметить, что в Go мы обычно не управляем потоками напрямую: планировщик сам распределяет горутины по системным потокам. Поэтому ситуация, когда поток, ранее выполнявший асинхронный I/O (например, на сокете), оказывается задействован для синхронного I/O на пайпе, вполне вероятна. В таком случае именно этот поток должен отменить асинхронный I/O через CancelIoEx, но сделать этого не может, так как заблокирован синхронной операцией.
Анализ от Microsoft Kernel Team
Для тех, кого интересуют технические подробности, ниже приведён детальный разбор дампов, выполненный совместно с Microsoft.
Комментарий Microsoft по hangtest:
В
hangtest.exe, поток (ffffa2029d6c3080) выполняет синхронныйWriteFileнаNamed Pipe. Так как это синхронный ввод‑вывод, доставка normal kernel APC отключена.
Другой поток (ffffa2029f0d7080) вызываетCancelIoEx()для того же FileObject. Он ставит в очередь APC для отмены IRP и ждёт его выполнения.
Однако APC не может быть доставлен, так как поток 0xffffa2029d6c3080 находится в синхронном ожидании.
Итог — оба потока блокируются.
Как уже отмечалось, критически важно не смешивать синхронный и асинхронный I/O. Для отмены синхронных операций используйтеCancelSynchronousIo().
Поток, выполняющий WriteFile (синхронный I/O)
Process Thread CID UserTime KernelTime ContextSwitches Wait Reason Time State hangtest.exe (ffffa202a18f0080) ffffa2029d6c3080 2d38.1cd0 63ms 344ms 3380 Executive 9m:35.406 Waiting Irp List: IRP File Driver Owning Process ffffa202a47f2b00 (null) Npfs hangtest.exe # Child-SP Return Call Site 0 ffffe881ff1f7e70 fffff8067f02a4d0 nt!KiSwapContext+0x76 1 ffffe881ff1f7fb0 fffff8067f0299ff nt!KiSwapThread+0x500 2 ffffe881ff1f8060 fffff8067f0292a3 nt!KiCommitThreadWait+0x14f 3 ffffe881ff1f8100 fffff8067f1f1744 nt!KeWaitForSingleObject+0x233 4 ffffe881ff1f81f0 fffff8067f406d96 nt!IopWaitForSynchronousIoEvent+0x50 5 (Inline) ---------------- nt!IopWaitForSynchronousIo+0x23 6 ffffe881ff1f8230 fffff8067f3cfdb5 nt!IopSynchronousServiceTail+0x466 7 ffffe881ff1f82d0 fffff8067f487ec0 nt!IopWriteFile+0x23d 8 ffffe881ff1f83d0 fffff8067f212005 nt!NtWriteFile+0xd0 9 ffffe881ff1f8450 00007fffdb70d5f4 nt!KiSystemServiceCopyEnd+0x25 a 00000055e4fff638 0000000000000000 0x7fffdb70d5f4 Irp Details: ffffa202a47f2b00 Thread Process Frame Count ============================= =========== ffffa2029d6c3080 hangtest.exe 2 Irp Stack Frame(s) # Driver Major Minor Dispatch Routine Flg Ctrl Status Device File === ================ ===== ===== ================ === ==== ======= ================ ================ ->2 \FileSystem\Npfs WRITE 0 IRP_MJ_WRITE 0 1 Pending ffffa202987985f0 ffffa2029f495670 ================================================================ ffffa2029f495670 Related File Object: 0xffffa2029f494d10 Device Object: 0xffffa202987985f0 \FileSystem\Npfs Vpb is NULL Flags: 0x40082 Synchronous IO Named Pipe Handle CreatedПоток, выполняющий CancelIoEx
FsContext: 0xffffc40ddc15a8c0 FsContext2: 0xffffc40ddc6bb291 Private Cache Map: 0x00000001 CurrentByteOffset: 0 Process Thread CID UserTime KernelTime ContextSwitches Wait Reason Time State hangtest.exe (ffffa202a18f0080) ffffa2029f0d7080 2d38.241c 31ms 391ms 4151 Executive 9m:35.406 Waiting # Child-SP Return Call Site 0 ffffe881fedd8fe0 fffff8067f02a4d0 nt!KiSwapContext+0x76 1 ffffe881fedd9120 fffff8067f0299ff nt!KiSwapThread+0x500 2 ffffe881fedd91d0 fffff8067f0292a3 nt!KiCommitThreadWait+0x14f 3 ffffe881fedd9270 fffff8067f4a72dd nt!KeWaitForSingleObject+0x233 4 ffffe881fedd9360 fffff8067f5218dc nt!IopCancelIrpsInThreadList+0x125 5 ffffe881fedd93b0 fffff8067f4a70d6 nt!IopCancelIrpsInThreadListForCurrentProcess+0xc4 6 ffffe881fedd9470 fffff8067f212005 nt!NtCancelIoFileEx+0xc6 7 ffffe881fedd94c0 00007fffdb70e724 nt!KiSystemServiceCopyEnd+0x25 8 00000055e45ffc88 0000000000000000 0x7fffdb70e724 This thread has been waiting 9m:35.406 on a kernel component request =============================================================== 0xffffa2029f494d10 Related File Object: 0xffffa2029fb0dd60 Device Object: 0xffffa202987985f0 \FileSystem\Npfs Vpb is NULL Event signalled Flags: 0x40082 Synchronous IO Named Pipe Handle CreatedВторой пример (реальный случай с сокетами и пайпами)
Кроме hangtest, мы предоставили Microsoft дамп ещё одного реального процесса, где проявился тот же механизм.
В нём поток сначала выполнял асинхронный ввод‑вывод на сокете, а затем оказался заблокирован на синхронном ReadFile для пайпа.
Поток (0xffffaf8602c90080) находится в ожидании синхронного
ReadFileна FileObject (ffffaf86107074b0) для Named Pipe. Доставка обычных kernel APC отключена.Другой поток (0xffffaf8602d06080) вызывает
CancelIoEx()для AFD‑эндпоинта.
Он ставит в очередь normal Kernel APC для отмены IRP и ждёт его выполнения.Прогресса не происходит, так как normal Kernel APC отключены у потока (0xffffaf8602c90080) из‑за синхронного ожидания I/O.
Фактически, асинхронный ввод‑вывод на сокете и синхронный ввод‑вывод на пайпе пересеклись в рамках одного потока. Когда возникла необходимость отменить I/O через CancelIoEx, это оказалось невозможно, и поток завис.
Стеки заблокированных потоков:
Process Thread CID UserTime KernelTime ContextSwitches Wait Reason Time State reducted_executable_name.exe (ffffaf85feb300c0) ffffaf8602c90080 e88.2b24 57s.703 24s.281 549327 Executive 3h:25:43.718 Waiting Irp List: IRP File Driver Owning Process ffffaf8600e76640 (null) Npfs reducted_executable_name.exe # Child-SP Return Call Site 0 ffffd005e29d4570 fffff8025d7071d7 nt!KiSwapContext+0x76 1 ffffd005e29d46b0 fffff8025d706d49 nt!KiSwapThread+0x297 2 ffffd005e29d4770 fffff8025d705ad0 nt!KiCommitThreadWait+0x549 3 ffffd005e29d4810 fffff8025dca1548 nt!KeWaitForSingleObject+0x520 4 (Inline) ---------------- nt!IopWaitForSynchronousIo+0x3e 5 ffffd005e29d48e0 fffff8025dc9ffc8 nt!IopSynchronousServiceTail+0x258 6 ffffd005e29d4990 fffff8025d877cc5 nt!NtReadFile+0x688 7 ffffd005e29d4a90 00007fff4e820094 nt!KiSystemServiceCopyEnd+0x25 8 000000002de1fbe8 00007fff4a9aa747 ntdll!ZwReadFile+0x14 9 000000002de1fbf0 000000000047337e KERNELBASE!ReadFile+0x77 a 000000002de1fc70 000000000000056c reducted_executable_name+0x7337e b 000000002de1fc78 000000c000573ec0 0x56c c 000000002de1fc80 0000000000008000 0xc000573ec0 d 000000002de1fc88 000000c001701d54 0x8000 e 000000002de1fc90 0000000000000000 0xc001701d54 Irp Details: ffffaf8600e76640 Thread Process Frame Count =========================== =========== ffffaf8602c90080 reducted_executable_name.exe 2 Irp Stack Frame(s) # Driver Major Minor Dispatch Routine Flg Ctrl Status Device File === ================ ===== ===== ================ === ==== ======= ================ ================ ->2 \FileSystem\Npfs READ 0 IRP_MJ_READ 0 1 Pending ffffaf85f7da2c00 ffffaf86107074b0 ============================================================== ffffaf86107074b0 Related File Object: 0xffffaf8602a1f6a0 Device Object: 0xffffaf85f7da2c00 \FileSystem\Npfs Vpb is NULL Flags: 0x40082 Synchronous IO Named Pipe Handle Created File Object is currently busy and has 0 waiters. Process Thread CID UserTime KernelTime ContextSwitches Wait Reason Time State reducted_executable_name.exe (ffffaf85feb300c0) ffffaf8602d06080 e88.2840 53s.969 24s.203 539612 Executive 3h:27:07.468 Waiting # Child-SP Return Call Site 0 ffffd005e2b02630 fffff8025d7071d7 nt!KiSwapContext+0x76 1 ffffd005e2b02770 fffff8025d706d49 nt!KiSwapThread+0x297 2 ffffd005e2b02830 fffff8025d705ad0 nt!KiCommitThreadWait+0x549 3 ffffd005e2b028d0 fffff8025dd06e87 nt!KeWaitForSingleObject+0x520 4 ffffd005e2b029a0 fffff8025dd6b377 nt!IopCancelIrpsInThreadList+0x11f 5 ffffd005e2b029f0 fffff8025dd06cd2 nt!IopCancelIrpsInThreadListForCurrentProcess+0xc3 6 ffffd005e2b02ab0 fffff8025d877cc5 nt!NtCancelIoFileEx+0xc2 7 ffffd005e2b02b00 00007fff4e8211c4 nt!KiSystemServiceCopyEnd+0x25 8 000000002e01fc28 00007fff4a9f9ef0 ntdll!ZwCancelIoFileEx+0x14 9 000000002e01fc30 000000000047337e KERNELBASE!CancelIoEx+0x10 a 000000002e01fc70 000000002e01fc88 reducted_executable_name+0x7337e 0xffffaf86`11746570 \Endpoint Device Object: 0xffffaf85f7db0b20 \Driver\AFD Vpb is NULL Flags: 0x6040400 Queue Irps to Thread Handle Created Skip Completion Port Queueing On Success Skip Set Of File Object Event On CompletionТаким образом, Microsoft подтвердила: это не баг в привычном смысле, а особенность реализации ввода‑вывода в Windows. Поведение CancelIoEx в такой ситуации действительно возможно, хотя и не отражено в официальной документации. К сожалению, эта особенность никак не обработана в Go, что делает её особенно неприятной — разработчик не ожидает блокировки и получает её внезапно уже в продакшне. А учитывая, что в Go отсутствует прямой контроль над потоками, подобная ситуация становится крайне проблемной.
Координация с разработчиками Go и Microsoft
В итоге мне удалось привлечь внимание к проблеме одного из разработчиков Go из Microsoft и скоординировать его взаимодействие с Microsoft Kernel Team. Совместный анализ подтвердил: ситуация воспроизводима и напрямую связана с особенностями работы APC при синхронном вводе‑выводе.
На мой взгляд, подобное поведение стоило бы либо корректно обработать на уровне ядра Windows, либо хотя бы явно указать в документации к CancelIoEx. Хотя, боюсь, первый вариант крайне малореалистичен: любое изменение в механизмах APC может повлечь трудно предсказуемые проблемы с обратной совместимостью. В результате имеем ситуацию, когда описание вводит в заблуждение: вызов обещает неблокирующее поведение, но на практике блокировка вполне возможна.
Практические последствия
-
В тестах Go это проявлялось как редкий flaky‑тест
TestPipeIOCloseRace, который время от времени «стрелял» в CI. -
В реальном сервисе поток, работавший с сетевым сокетом асинхронно, оказался планировщиком задействован для синхронной операции на пайпе — и завис в
CancelIoEx. -
Снаружи процесс продолжал выглядеть «живым», но внутри одна из ключевых горутин навсегда оказывалась заблокированной.
-
Особенно неприятно, что проблема крайне сложна для воспроизведения: на тестовых стендах она может не проявиться неделями, а в продакшене внезапно «выстрелить» и повесить критический сервис.
Возможные решения
На данный момент есть несколько способов минимизировать риск зависания:
-
Корректная работа с дескрипторами
-
Не вызывать
CancelIoExдля синхронных дескрипторов (созданных безFILE_FLAG_OVERLAPPED). -
Для отмены синхронных операций использовать
CancelSynchronousIo, как рекомендует Microsoft.
Вместе эти меры устраняют риск блокировки, но требуют изменений в рантайме Go.
-
-
Минимизировать использование пайпов
Если есть возможность, лучше вовсе отказаться от применения пайпов в критичных местах кода. Это существенно снижает вероятность столкнуться с проблемой. -
Дождаться официального фикса
Команда Go подтвердила проблему и планирует её исправление в версии 1.26
(issue #64482).
Выводы
Этот случай показал, что редкий flaky‑тест способен скрывать вполне реальную и опасную для продакшена проблему.
-
Вызов
CancelIoExна синхронных дескрипторах пайпов может намертво заблокировать поток, несмотря на то, что документация утверждает обратное. -
В Go планировщик может назначить поток, ранее выполнявший асинхронный I/O, на синхронную операцию. В такой ситуации поток не сможет отменить собственные асинхронные операции.
-
До исправления в Go 1.26 разработчикам остаются только обходные пути.
⚡️ Если ваш Go‑сервис под Windows зависает в CancelIoEx, а воспроизвести проблему не удаётся, надеюсь, этот текст поможет вам разобраться в её причинах и найти временный обходной путь.
ссылка на оригинал статьи https://habr.com/ru/articles/932760/
Добавить комментарий