package wine import ( "encoding/json" "log/slog" "strconv" "strings" "sync/atomic" "time" ) const diagnosticLineLimit = 4096 // helperDiagnostics is written only by os/exec's stderr copier. It drains // arbitrary Wine output without waiting for the log sink. Each helper gets a // bounded line buffer, queue and rate window. After cmd.Wait, its logging // worker drains the remaining records independently of process shutdown. type helperDiagnostics struct { lines chan string done chan struct{} partial []byte overlong bool window time.Time seen map[string]bool suppressed atomic.Uint64 // onReady is installed before the first Write and receives valid ready // records before diagnostic throttling. It runs on the stderr copier // (or finish for a final partial line) and must only publish bounded // state, never log, block, or supervise processes. onReady func(helperReady) } // helperReady is the helper's startup status record. Older helpers omit // hook_exclusions and therefore report zero, which is accurate for them. type helperReady struct { Reader string `json:"reader"` ControlsEnabled bool `json:"controls_enabled"` Controller bool `json:"controller"` Review bool `json:"review"` MSAAWorker bool `json:"msaa_worker"` WinEvents bool `json:"win_events"` MenuHook bool `json:"menu_hook"` InputHook bool `json:"input_hook"` Host32Started bool `json:"host32_started"` ControlPoll bool `json:"control_poll"` HookExclusions int `json:"hook_exclusions"` } func parseHelperReady(line string) (helperReady, bool) { body, found := strings.CutPrefix(line, "ready ") if !found { return helperReady{}, false } var status helperReady if err := json.Unmarshal([]byte(body), &status); err != nil || status.Reader == "" { return helperReady{}, false } return status, true } func newHelperDiagnostics() *helperDiagnostics { return &helperDiagnostics{ lines: make(chan string, 64), done: make(chan struct{}), seen: make(map[string]bool), } } func (output *helperDiagnostics) Write(data []byte) (int, error) { for _, char := range data { if char == '\n' { if output.overlong { output.suppressed.Add(1) } else { output.queueLine(string(output.partial)) } output.partial = output.partial[:0] output.overlong = false } else if !output.overlong { if len(output.partial) == diagnosticLineLimit { output.overlong = true output.partial = output.partial[:0] } else { output.partial = append(output.partial, char) } } } return len(data), nil } func (output *helperDiagnostics) queueLine(line string) { line = strings.TrimSuffix(line, "\r") // Do not mix arbitrary Wine/application stderr into reader diagnostics. if !strings.HasPrefix(line, "wine-access: ") { return } // Readiness controls exclusion fallback and must survive a full queue, // diagnostic throttling, and a slow log sink. The line buffer above // bounds parsing independently of how many diagnostics are retained. record := strings.TrimPrefix(line, "wine-access: ") if output.onReady != nil { if ready, valid := parseHelperReady(record); valid { output.onReady(ready) } } now := time.Now() if now.Sub(output.window) >= 10*time.Second { output.window = now clear(output.seen) } if output.seen[line] || len(output.seen) >= 32 { output.suppressed.Add(1) return } output.seen[line] = true select { case output.lines <- record: default: output.suppressed.Add(1) } } // finish is called after Wait has stopped the stderr copier, including its // WaitDelay deadline. It never waits for a slow log sink during helper shutdown. func (output *helperDiagnostics) finish() { if output.overlong { output.suppressed.Add(1) } else if len(output.partial) != 0 { output.queueLine(string(output.partial)) } close(output.lines) } func (output *helperDiagnostics) logRecords(logger *slog.Logger) { defer close(output.done) ticker := time.NewTicker(10 * time.Second) defer ticker.Stop() reportSuppressed := func() { if count := output.suppressed.Swap(0); count != 0 { logger.Warn("Wine helper diagnostics suppressed", "count", count) } } for { select { case line, open := <-output.lines: if !open { reportSuppressed() return } logHelperRecord(logger, line) case <-ticker.C: reportSuppressed() } } } func logHelperRecord(logger *slog.Logger, line string) { if body, found := strings.CutPrefix(line, "identity "); found { var identity struct { Version string `json:"version"` Revision string `json:"revision"` Modified bool `json:"modified"` } if err := json.Unmarshal([]byte(body), &identity); err != nil || identity.Version == "" || identity.Revision == "" { logger.Warn("Invalid Wine helper identity record") return } logger.Info("Wine accessibility helper identity", "version", identity.Version, "revision", identity.Revision, "modified", identity.Modified) return } if strings.HasPrefix(line, "ready ") { status, valid := parseHelperReady(line) if !valid { logger.Warn("Invalid Wine helper initialization record") return } logger.Info("Wine accessibility helper initialized", "reader", status.Reader, "controls_enabled", status.ControlsEnabled, "controller", status.Controller, "review", status.Review, "msaa_worker", status.MSAAWorker, "win_events", status.WinEvents, "menu_hook", status.MenuHook, "input_hook", status.InputHook, "host32_started", status.Host32Started, "control_poll", status.ControlPoll, "hook_exclusions", status.HookExclusions) return } // The plain exclusion-count line is expected startup evidence (it is // emitted even when the helper then exits early), while a rejected // exclusion value stays a warning through the default branch. if hookExclusionCountLine(line) || strings.HasPrefix(line, "reader event replies resumed after ") || line == "another helper already owns this Wine desktop" || line == "disabled by command-line options" { logger.Info("Wine accessibility helper diagnostic", "diagnostic", line) } else { logger.Warn("Wine accessibility helper diagnostic", "diagnostic", line) } } func hookExclusionCountLine(line string) bool { rest, found := strings.CutPrefix(line, "hook exclusions for ") if !found { return false } number, found := strings.CutSuffix(rest, " program(s)") if !found || number == "" { return false } count, err := strconv.Atoi(number) return err == nil && count >= 0 && strconv.Itoa(count) == number }