This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

Finding the DOS I/O delay bug — a debugging story

Written by Claude Code

Related PR: #4991

This is the story of how a two-year-old crash workaround (vga_render_per_scanline) turned out to be hiding a ~20-year-old timing bug in DOSBox's DOS file I/O code, and how we found it in one evening of instrumented runs. It's written as a manual: every step describes the technique used, why that technique and not another, and what a human with a debugger and some patience could have done to get the same answer. Along the way it explains the PC internals the investigation touched — the interrupt vector table, the PIT timer, VGA retrace — as they appear in the disassembled code of a real 1994 game.

The cast:

• The games: Ishar 3, Deus, Robinson's Requiem, Time Warriors (all Silmarils, shared engine), and Dragon's Lair CD. All crash at startup above a per-game cycles threshold.
• The suspect everyone watched for two years: per-scanline VGA rendering. Crashes started when 0.81.0 made it the default; disabling it (vga_render_per_scanline = off) made the games work.
• The actual culprit: a cycle-accounting shortcut in modify_cycles() in dos.cpp, in the DOS file read/write handler, dating back to early DOSBox.

---

Part 1: Archaeology before instrumentation

The first hours were spent without running anything. Before you measure, you collect every fact that already exists, because each one constrains the hypothesis space for free:

• The workaround's own history (git log, PR #3507, issues #3501, #3512, #4598, release notes). Key detail found here: the original 0.81.1 patch toggled only vga.draw.parts_total — 4 draw events per frame vs one per scanline. Same machine type, same timing tables, same everything else. So whatever the mechanism was, it had to flow through the number of scheduled events, because that's all the flag changed.
• Cross-fork data points are experiments someone already ran. Issue #3501 recorded that DOSBox SVN crashes Deus at ~4–5k cycles under machine = vgaonly but at ~42–45k under svga_s3. Same ~10× ratio, 2005-era code base. Conclusion: the bug predates Staging and lives in something both forks share.
• A 2005 VOGONS thread about Robinson's Requiem already contained the two classic workarounds: "lower cycles during startup" and, curiously, "core=dynamic also fixes it". Old forum threads are archaeology gold — they record symptoms against code bases that no longer exist.
• GOG ships Robinson's Requiem with a cycles cap in its stock DOSBox config. So the "too fast = crash" behaviour is a known property of the game, not something Staging invented.

Lesson: an hour of reading issues, forums, and git log -S is worth days of blind debugging. You're building a fact table that any theory must fit. By the end of this phase the fact table said: cycles-dependent, event-density- dependent, fork-independent, rendering-code-suspicious-but-unproven.

---

Part 2: Static analysis, and the value of being provably wrong

Next: read the emulator code and enumerate every channel through which the draw-event count could possibly reach the guest. This produced a surprisingly short list, and item by item it evaporated:

• The draw events themselves only read VRAM and produce host-side pixels. They raise no IRQs and write no guest state.
• The VGA status register (port 0x3DA — retrace and display-enable bits) is computed from PIC_FullIndex() and the timing tables, identical in both modes.
• PIC events fire at exact scheduled times; the queue itself creates the CPU slice boundaries, so an event never fires late because of another event.
• IRQ delivery is prompt in both modes: raising an IRQ from a port write truncates the current slice (PIC_Controller::activate() zeroes CPU_Cycles), and PIC_ActivateIRQ() adds a deliberate ~2-cycle pickup delay. Slice length does not add IRQ latency.
• Sliced REP MOVS instructions cost exactly count cycles regardless of how many slice boundaries interrupt them (the accounting in core_normal/string.h balances).

The conclusion of the static pass was a contradiction: "at fixed cycles with the normal core, these two modes should be guest-identical — yet five games reproducibly disagree." That sounds like failure. It's the opposite: a model that makes a falsified prediction tells you exactly what kind of experiment to run next. We now knew we were hunting for a channel not on the list, and that it had to be findable by differential measurement, because the difference was real and deterministic.

Lesson: write your model down and make it predict something. "I don't see how X can matter" is worthless; "by this reasoning X cannot matter, and yet it does" is a precision instrument.

---

Part 3: The instrumentation toolkit

All instrumentation was temporary LOG_MSG code, gated behind environment variables so a single binary could run clean or instrumented. Each instrument existed to answer one specific question. This is the part worth stealing.

3.1 The IRQ delivery trace

Question: what interrupts flow through the system, and through which vectors?

One hook in PIC_Controller::start_irq() — the single choke point every delivered hardware interrupt passes through:

IRQTRACE: 1679.0186  INT 08h (IRQ 0) delivered  vec=0268:43F0  pmode=1
          CS:IP=002B:00001E2A  SS:SP=0033:DFFFEDA8  EAX=00010000 ...

Per line: emulated time in ms, interrupt number, the current real-mode vector for it, protected/real mode, and the interrupted CS:IP plus registers. Three non-obvious payoffs:

• The interrupted CS:IP is a free profiler. The timer fires 60 times a second; where it lands tells you what the game is doing. Watching the samples walk through 1E2A → 1E4C → 1E72 → 1E72 and then seeing the game die identified the calibration loop before we ever saw its code.
• The vector column verifies hook state at every delivery — is the game's handler installed right now, or the BIOS default?
• Registers at delivery time expose loop-counter values for free. Later, EAX at each tick gave us the game's iteration counter without knowing any memory addresses.

Manual equivalent: the DOSBox heavy-debugger build can breakpoint interrupts (bpint 08), but the value here is aggregation — thousands of deliveries timestamped and greppable, not one stop.

3.2 The interrupt vector table watch

Question: does the IVT really get trashed (as the crash screen suggested)?

The real-mode IVT is 256 four-byte far pointers at physical address 0. An 0.5 ms poll comparing all 256 entries against a shadow copy, logging diffs:

IRQTRACE: 1662.6014  IVT 09h changed 0188:0020 -> 0268:43F4

This is a poor man's memory watchpoint — far cruder than the debugger's bpm, but it never stops execution and produces a timeline. That timeline single-handedly rewrote the theory of the crash:

• Every change was an orderly hook or unhook. Nothing ever pointed into garbage.
• The "crash" sequence was: game hooks IRQ5 vector → waits 236 ms → gives up, hooks IRQ7 instead (classic Sound Blaster detection: try address 220h's default IRQ, then the alternative) → hooks keyboard and timer → 70 ms later everything is unhooked again in one batch and INT 23h/24h flip back to COMMAND.COM's values.
• That last signature is the tell: DOS restores vectors 22h/23h/24h from the PSP when a process terminates. The game wasn't crashing through a bad vector — it was calling exit. The IVT-corruption theory died there, along with any theory involving wild jumps.

Lesson: before assuming corruption, log the suspect data structure's transitions. Corruption looks like garbage appearing; a clean shutdown looks like bookkeeping — and they're trivial to tell apart on a timeline.

3.3 The dummy event injector — the decisive experiment

Question: is it the rendering, or merely the schedule?

The flag changed two things at once: what gets rendered per event, and how many events exist. Classic confounded variable. So: keep chunked rendering (flag off) and inject no-op PIC events at scanline rate — events that do literally nothing:

static void VGA_DummyLineEvent(uint32_t)
{
    if (++dummy_lines_done < vga.draw.lines_total)
        PIC_AddEvent(VGA_DummyLineEvent, vga.draw.delay.vdend / vga.draw.lines_total);
}

Result: the game died identically, same 4-tick window, same clean self-exit. Event density alone was the causal variable — the entire VGA rendering path was exonerated in one run, and the event frequency became the knob that tunes the crash threshold.

Lesson: when the suspicious change bundles several effects, synthesise each effect in isolation. A no-op version of the suspect is the cleanest control experiment there is.

3.4 Per-tick differential counters

Question: what is different, per unit of guest time, between a good and a bad run?

Counters reported and reset at every timer-tick delivery: I/O port accesses by class (0x3DA reads, PIT, SB, other), CPU exceptions by vector, PIC_RunQueue invocations (slice count), and the running total of CPU_IODelayRemoved.

Two of these broke the case:

• The slice counter quantified the density difference inside the game's measurement window: ~80 slices per 16.66 ms tick interval chunked vs ~730 per-scanline.
• The iodelay counter caught an impossible number. One tick interval showed ~600,000–765,000 delay cycles removed while the port counters showed ~2,000 I/O accesses — about 30,000 cycles' worth. When two independent measurements of "the same" quantity disagree by 20×, the discrepancy is the lead. grep CPU_IODelayRemoved across the tree listed every writer of that accumulator, and there it was in dos.cpp:

} else {
    CPU_IODelayRemoved += CPU_Cycles/*-5*/; // don't want to mess with negative
    CPU_Cycles = 5;
}

A DOS file-I/O delay of 4 cycles per byte, silently capped at whatever remains of the current CPU slice. Slice length is set by event density. There's the whole bug, with a confession in the comment.

Lesson: conservation checks localise bugs fast. Sum the parts and compare against the whole (slice grants vs tick length; unit cost × count vs total). Bookkeeping that doesn't balance points at the exact subsystem lying to you.

3.5 Reading the suspect's diary: in-guest code dumps

Question: what does the game's calibration actually measure?

The IRQ trace gave the loop's neighbourhood (CS:IP ≈ 002B:1E2A–1E72, protected mode). To read it, dump the bytes from inside the emulator at delivery time:

Descriptor desc = {};
cpu.gdt.GetDescriptor(SegValue(cs), desc);       // handles GDT and LDT selectors
const auto base = desc.GetBase();                // linear base of the code segment
// mem_readb(base + offset) reads through paging — dump 1C80h..1F7Fh as hex

Then feed the hex to ndisasm -b32. Protected-mode note: selector 002B has the TI bit set (an LDT selector, typical for a DOS extender), and the code turned out to be a 32-bit segment — if the disassembly looks like nonsense, try the other operand size first.

A one-shot dump of 768 bytes was enough to reconstruct the entire calibration apparatus (annotated below), and dumping the game's own variables (mem_readw at addresses learned from the disassembly) at every tick let us watch its bookkeeping evolve — which killed one of our best-looking hypotheses in Part 4.

Manual equivalent: the heavy debugger's memory dump + any disassembler; the trick is knowing which addresses matter, and the interrupted-CS:IP samples answer exactly that.

---

Part 4: Following the evidence, including when it disagrees with you

The instrumented runs proceeded as numbered experiments (R0, R1, …), each with a prediction written down first. Two moments deserve retelling because the failures were the productive part:

The burn-loop model collapsed. After decoding the counting loop, the arithmetic fit a beautiful story: the loop costs ~6 cycles/iteration under per-scanline events and ~41 under chunked, and the ratio matched the crash thresholds. Round-3 traces then showed EAX (the loop counter) saturating at 0x7FFF in both modes, and the stored result (iterations/40 = 819) — identical in the passing and crashing runs. The verdict couldn't be based on the loop count. A model that fits four data points can still be wrong; only a direct measurement of the intermediate quantity settles it.

The exceptions theory died in one line. The best remaining explanation for "cycles vanish invisibly in chunked mode" was CPU exceptions — page faults through the DOS extender execute guest code with no IRQ trace entry. The per-tick exception counters came back none inside the window in both modes. One counter, one run, theory gone. That left arithmetic bookkeeping as the only suspect standing — which is what sent us grepping for CPU_IODelayRemoved writers with fresh eyes.

Lesson: pre-registered predictions turn wrong theories into progress. If you only look for confirming evidence, a wrong model can absorb weeks.

---

Part 5: What the disassembly teaches — a small DOS internals course

The game's startup code is a compact tour of how DOS-era software actually used the machine. The excerpts below are from the real Ishar 3 dump (CS base 0x10000000, offsets as shown).

5.1 The PIT, and reading a running counter

The 8254 Programmable Interval Timer runs at 1,193,182 Hz (a historical artefact: 4 × the NTSC colour-burst frequency ÷ 3, inherited from the CGA-era clock tree). Channel 0 counts down from a programmable divisor and fires IRQ 0 on wrap; DOS's default divisor of 65536 gives the famous 18.2 Hz tick.

The game measures the length of one video frame in PIT ticks:

1D87  cli
      mov  al, 0x36          ; command 00 11 011 0: channel 0, lo/hi byte,
      out  0x43, al          ;   mode 3 (square wave), binary
      mov  ax, 0xFFFF
      out  0x40, al          ; divisor low byte
      xchg al, ah
      out  0x40, al          ; divisor high byte  -> counter reloads at 65535
      sti
      ...                    ; (wait exactly one video frame, see 5.3)
1DA1  mov  al, 0x06          ; latch command for channel 0
      out  0x43, al
      in   al, 0x40          ; latched count, low byte
      mov  ah, al
      in   al, 0x40          ; latched count, high byte
      xchg al, ah
      neg  ax
      add  ax, -1            ; elapsed = 65535 - count
      shr  ax, 1             ; MODE 3 COUNTS DOWN BY TWO per input clock!
      sub  ax, 0x64          ; subtract a fudge constant (overhead)
      mov  [0x12D2B], ax     ; = PIT ticks per frame (~17,031 for 70 Hz)

Details worth knowing:

• The latch command (out 0x43 with the two RW bits zero) atomically copies the running count into a holding register, so the two subsequent 8-bit reads can't straddle a decrement. Reading without latching gives torn values.
• Mode 3 decrements by 2 each input clock (it generates a square wave by counting each half-period). Software using mode 3 as a stopwatch must halve the delta — that's the shr ax, 1, and if you didn't know the hardware detail, the instruction would look like a bug.
• Reprogramming channel 0 changes the system tick rate out from under DOS — which is why well-behaved games hook INT 8 first and restore everything on exit. (Amusingly, on its error path Ishar 3 restores the vector but leaves the PIT at 60 Hz — visible in our traces as DOS idling at the wrong tick rate after the "crash".)

5.2 The IVT, hooking, and how a process exit looks

In real mode, interrupt vector n lives at physical address n × 4: two bytes of offset, two of segment. Hardware IRQs 0–7 map to INT 08h–0Fh, IRQs 8–15 to INT 70h–77h. Three ways code changes a vector:

1. Write the four bytes directly (with interrupts disabled, if you're careful).
2. DOS INT 21h AH=25h (set) / AH=35h (get) — what most programs use.
3. Under a DOS extender, the extender's own service — Ishar 3 calls AX=2506h, CL=vector, DS:EDX=handler to install a protected-mode handler; the extender then re-points the real-mode IVT entry at its own reflection stub (0266:43F0 in our traces) which switches modes and calls the game.

The traced hook/unhook timeline also showed the canonical termination signature: DOS restores INT 22h (terminate address), 23h (Ctrl-C) and 24h (critical error) from fields in the exiting program's PSP. When you see those three flip back to COMMAND.COM's segments, a process just exited via INT 21h AH=4Ch — nobody "crashed"; someone called exit().

5.3 VGA retrace on port 0x3DA

Input Status Register #1: bit 0 = display enable (set during any blanking), bit 3 = vertical retrace (set during the vertical sync pulse, ~once per frame). The idiom for synchronising to the start of a retrace needs two loops, because if you only wait for "bit set" you might land mid-pulse:

1D7D  in   al, dx            ; dx = 0x3DA
      test al, 8
      jnz  1D7D              ; wait while IN retrace (finish current pulse)
1D82  in   al, dx
      test al, 8
      jz   1D82              ; wait for the NEXT retrace to begin
      ; <- we are now at a frame edge, accurate to a few microseconds

Games used this for tear-free page flips and as a free ~70 Hz timing reference. Ishar 3 brackets its PIT measurement between two such edges — that's how "PIT ticks per frame" in 5.1 is exact. Note what this implies for emulator authors: the guest can compare two independent clocks (PIT vs vertical retrace) and notice if either is off.

5.4 Defensive timeouts — 1994-style error handling

Every wait in the calibration has an escape hatch. Waiting for the first timer tick after hooking INT 8:

1D3E  mov  ecx, 0xFDE8       ; budget: 65,000 iterations
1D43  push ax
      pop  ax                ;   2-instruction busy filler
      cmp  word [0x12D29], 0 ; has the tick handler stored a PIT latch yet?
      jnz  1D5C              ;   yes -> proceed
      loop 1D43              ;   no  -> decrement ECX, retry
1D53  mov  word [0x12D29], 0xFFFF   ; budget exhausted -> sentinel value

And the counting loop itself is saturating rather than wrapping:

1E5C  mov  ebx, [0x129A4]    ; touch memory (defeat trivial optimisation)
      mov  [0x129A4], ebx
      add  ebx, ebx
      cmp  ax, 0x7FFF        ; counter capped at 32,767
      jz   1E72              ;   (no 16-bit wraparound bugs here!)
      inc  ax
1E72  cmp  byte [0xFF69], 2  ; ISR increments this once per tick
      jnz  1E5C              ; run for exactly two tick intervals

Silmarils clearly got burned by fast machines before: budgets, sentinels and saturation everywhere. The irony is that this defensive code is exactly what turned an emulator timing bug into a hard startup abort — the sanity check worked as designed, against an insane machine.

---

Part 6: The emulator-side mental model

To see why the bug was invisible for so long, you need three DOSBox concepts in one picture:

1. Cycles: cycles = N means the CPU core may execute N cost-units of instructions per emulated millisecond ("tick"). CPU_CycleMax is the budget, CPU_CycleLeft what remains of the tick.
2. The event queue: everything periodic (PIT, mixer, VGA drawing…) schedules callbacks at exact emulated times on the PIC queue.
3. Slices: PIC_RunQueue() grants the core only the cycles up to the next due event: CPU_Cycles = min(cycles to next event, CPU_CycleLeft). The core runs, the event fires, repeat. So slice length = event density, and CPU_Cycles at any instant is "cycles until the next event".

Given that picture, the bug pattern is easy to state and easy to grep for: any guest-visible cost that is clamped against CPU_Cycles is a function of event density, which is an emulator implementation detail no real machine ever had. modify_cycles() was the big one (4 cycles/byte of file I/O, capped at the slice); the same pattern exists in miniature in the port I/O delays (IO_USEC_read_delay(), ~19 cycles capped) and a couple of other places. On real hardware, a disk transfer takes the time it takes — it does not get faster because the video card is busier.

The fix is one line of arithmetic: apply the delay in full and let CPU_Cycles go negative; the tick accounting carries the debt into the next slices. Determinism restored, and the two rendering modes became guest-identical — confirmed by the games themselves.

---

Part 7: The method, distilled

If you want the reusable checklist out of this whole story:

1. Collect the existing facts first — issues, forums, release notes, sibling forks. Every recorded symptom is an experiment you don't have to run.
2. Enumerate the possible channels from cause to effect by reading the code, and write down what your model predicts. A falsified prediction is the best possible outcome.
3. Make the repro boring: fixed cycles, fixed core, one variable per run, verdicts recorded in filenames.
4. Instrument choke points, not everything: one hook where all interrupts are delivered, one poll where the vectors live, counters reset on a natural clock (the timer tick) so runs can be compared line by line.
5. Design control experiments that isolate variables — the no-op event injector is the template: same schedule, none of the side effects.
6. Run conservation checks and chase any number that doesn't balance. Our 20× mismatch between counted I/O and removed delay cycles was the bug, wearing an accounting disguise.
7. Read the guest's code once you know where to look — the interrupted CS:IP tells you where; a descriptor lookup, a hex dump and ndisasm do the rest.
8. Let measurements kill your favourite theory quickly — saturating counters and zero exception counts each destroyed a well-fitted model in one run. The faster your darlings die, the faster the real cause runs out of places to hide.

The final scoreboard: a two-year-old workaround setting, five "broken" games, one 20-year-old accounting shortcut — found with roughly a dozen short instrumented runs, none of which required knowing anything about the games in advance. The games told us everything themselves, one timer tick at a time.