Я не считаю себя специалистом по 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
, а воспроизвести проблему не удаётся, надеюсь, этот текст поможет вам разобраться в её причинах и найти временный обходной путь.
durnoy
Расскажите, как удалось привлечь Windows Kernel team.
SerpentFly Автор
Microsoft Premier Support