github-starred/RhapsodiOS

Watch

Fork 0

mirror of https://github.com/RhapsodiOS/RhapsodiOS.git synced 2026-11-03 22:01:40 -07:00

[GH-ISSUE #26] kernel: i386 IOGetTimestamp / clock_get_counter(System) steps backwards by one tick #23

New issue

Closed

opened 2026-11-03 22:02:28 -07:00 by gitea-mirror · 3 comments

gitea-mirror commented

2026-11-03 22:02:28 -07:00

Owner

Originally created by @raynorpat on GitHub (Sep 25, 2026).
Original GitHub issue: https://github.com/RhapsodiOS/RhapsodiOS/issues/26

Symptom

On i386 (QEMU 11.1 TCG, -M pc -cpu pentium), IOGetTimestamp() sometimes returns a lower value than a call made microseconds earlier. It showed up in PS2MouseIntHandler (src/drivers-i386/input/drvPS2Mouse/.../PS2Mouse.m): two consecutive bytes of one 3-byte packet had newStamp < lastTimeStamp. The unsigned ns_time_t difference wrapped, and a diagnostic (int)((newStamp - lastTimeStamp) / 1000000) printed -140462621 ms seven times during one set of mouse sweeps. The PS/2 driver now guards against this (1a80dece9 on claude/ps2-mouse-qemu-erratic-35b897), but the clock is still wrong.

-140462621 is what the int cast gives for an unsigned wrap of a step between about 9.55 and 10.55 ms, so the clock goes back by one tick (HZ=100).

Cause

IOGetTimestamp() → clock_get_counter(System) → system_time_stamp() in src/kernel-7/machdep/i386/machine_clock.c. It adds the latched 8254 channel-0 count to a tick counter that the IRQ0 handler advances. If the PIT has wrapped but IRQ0 has not been serviced yet, the read sees current > last_timer_count and adds one tick. But it also stores the post-wrap count as last_timer_count, so the next read before the interrupt (current below that stored value) does not detect the wrap and drops the tick. The clock goes back by one tick. TCG's late interrupt delivery makes that window easy to hit.

Proposed fix (Apple divergence)

Once a wrap is detected, store 0 in last_timer_count. The count is never 0 in mode 2 (NDIV), so every later read until IRQ0 runs still counts the pending tick. The interrupt handler then resets last_timer_count to timer_const as before. Fix in progress; kernel build running on the i386 guest.

Remaining limit (not addressed): if two wraps pass before IRQ0 is serviced, a tick can still be lost.

Other callers affected by a backward step

Being audited. Callers of clock_get_counter(System) include sched_usec_elapsed / tick_stamp (kern/mach_clock.c), hardclock SIMPLE_CLOCK delta (bsd/kern/kern_clock.c), microboot (kern/ns_timer.c), kern_timestamp (kern/time_stamp.c), deadline_from_interval (kern/thread_call.c), and IOGetTimestamp users in drivers; clock_get_counter(Calendar) (microtime) shares the same base.

Originally created by @raynorpat on GitHub (Sep 25, 2026). Original GitHub issue: https://github.com/RhapsodiOS/RhapsodiOS/issues/26 ## Symptom On i386 (QEMU 11.1 TCG, `-M pc -cpu pentium`), `IOGetTimestamp()` sometimes returns a lower value than a call made microseconds earlier. It showed up in `PS2MouseIntHandler` (`src/drivers-i386/input/drvPS2Mouse/.../PS2Mouse.m`): two consecutive bytes of one 3-byte packet had `newStamp < lastTimeStamp`. The unsigned `ns_time_t` difference wrapped, and a diagnostic `(int)((newStamp - lastTimeStamp) / 1000000)` printed `-140462621 ms` seven times during one set of mouse sweeps. The PS/2 driver now guards against this (1a80dece9 on `claude/ps2-mouse-qemu-erratic-35b897`), but the clock is still wrong. `-140462621` is what the int cast gives for an unsigned wrap of a step between about 9.55 and 10.55 ms, so the clock goes back by one tick (HZ=100). ## Cause `IOGetTimestamp()` → `clock_get_counter(System)` → `system_time_stamp()` in `src/kernel-7/machdep/i386/machine_clock.c`. It adds the latched 8254 channel-0 count to a tick counter that the IRQ0 handler advances. If the PIT has wrapped but IRQ0 has not been serviced yet, the read sees `current > last_timer_count` and adds one tick. But it also stores the post-wrap count as `last_timer_count`, so the next read before the interrupt (current below that stored value) does not detect the wrap and drops the tick. The clock goes back by one tick. TCG's late interrupt delivery makes that window easy to hit. ## Proposed fix (Apple divergence) Once a wrap is detected, store 0 in `last_timer_count`. The count is never 0 in mode 2 (NDIV), so every later read until IRQ0 runs still counts the pending tick. The interrupt handler then resets `last_timer_count` to `timer_const` as before. Fix in progress; kernel build running on the i386 guest. Remaining limit (not addressed): if two wraps pass before IRQ0 is serviced, a tick can still be lost. ## Other callers affected by a backward step Being audited. Callers of `clock_get_counter(System)` include `sched_usec_elapsed` / `tick_stamp` (kern/mach_clock.c), `hardclock` SIMPLE_CLOCK delta (bsd/kern/kern_clock.c), `microboot` (kern/ns_timer.c), `kern_timestamp` (kern/time_stamp.c), `deadline_from_interval` (kern/thread_call.c), and `IOGetTimestamp` users in drivers; `clock_get_counter(Calendar)` (microtime) shares the same base.

gitea-mirror

2026-11-03 22:02:28 -07:00

closed this issue
added the
bug
label

gitea-mirror commented

2026-11-03 22:02:30 -07:00

Author

Owner

@raynorpat commented on GitHub (Sep 25, 2026):

Fix committed as cd9fc5abd on claude/compassionate-zhukovsky-279f1a (not yet merged). rbuild kernel --toolchain for i386 built it on the 127.0.0.1:2222 guest in a private root (/build/clockfix/out/kernel-154.5.1-7-i386.apk); machine_clock.c compiles with no warnings. Not boot-tested yet.

Also fixed in d585eea92: the shared gcc-darwin-i386.conf had no /usr/local/bin on path=, so rbuild kernel failed with relpath: not found. The guest's /build/src copy is updated too.

Callers affected by a backward step (not changed)

Kernel, low risk: hardclock (SIMPLE_CLOCK delta), tick_stamp and sched_usec_elapsed (via recompute_priorities) all read the clock inside the IRQ0 handler, right after the tick is added. kern_timestamp and microboot pass the error through to user space and to the user-space driverkit IOGetTimestamp.

Spurious timeouts (now - start unsigned, compared to a limit):

drvNE2k/.../NE2K.m lines 164, 1106 and 1144: false "Card failure" or Tx RDC timeout and a card reset (the NIC the QEMU guest uses)
drvAMDPCNet32II/.../AMDPCNet32II.m:146

Same bug as PS/2: drvSerialPointingDevice/.../SerialPointingDevice.m lines 656, 748 and 772: the 40 ms gap check would throw away a valid packet.

Wrong statistics only: AMD_x86.m:701 interval test; the totalTime/latentTime numbers in EIDE IdeDiskInternal.m, BusLogic, Adaptec 1542B/6X60 and AMD SCSI.

Harmless: IOEthernet and IOTokenRing compare absolute deadlines, so a backward step only makes a timeout slightly longer. EventInput's periodic scheduling already handles a clock that appears to wrap around.

@raynorpat commented on GitHub (Sep 25, 2026): Fix committed as cd9fc5abd on `claude/compassionate-zhukovsky-279f1a` (not yet merged). `rbuild kernel --toolchain` for i386 built it on the 127.0.0.1:2222 guest in a private root (`/build/clockfix/out/kernel-154.5.1-7-i386.apk`); `machine_clock.c` compiles with no warnings. Not boot-tested yet. Also fixed in d585eea92: the shared `gcc-darwin-i386.conf` had no `/usr/local/bin` on `path=`, so `rbuild kernel` failed with `relpath: not found`. The guest's `/build/src` copy is updated too. ### Callers affected by a backward step (not changed) **Kernel, low risk:** `hardclock` (SIMPLE_CLOCK delta), `tick_stamp` and `sched_usec_elapsed` (via `recompute_priorities`) all read the clock inside the IRQ0 handler, right after the tick is added. `kern_timestamp` and `microboot` pass the error through to user space and to the user-space driverkit `IOGetTimestamp`. **Spurious timeouts** (`now - start` unsigned, compared to a limit): - `drvNE2k/.../NE2K.m` lines 164, 1106 and 1144: false "Card failure" or Tx RDC timeout and a card reset (the NIC the QEMU guest uses) - `drvAMDPCNet32II/.../AMDPCNet32II.m:146` **Same bug as PS/2:** `drvSerialPointingDevice/.../SerialPointingDevice.m` lines 656, 748 and 772: the 40 ms gap check would throw away a valid packet. **Wrong statistics only:** `AMD_x86.m:701` interval test; the totalTime/latentTime numbers in EIDE `IdeDiskInternal.m`, BusLogic, Adaptec 1542B/6X60 and AMD SCSI. **Harmless:** `IOEthernet` and `IOTokenRing` compare absolute deadlines, so a backward step only makes a timeout slightly longer. `EventInput`'s periodic scheduling already handles a clock that appears to wrap around.

gitea-mirror commented

2026-11-03 22:02:30 -07:00

Author

Owner

@raynorpat commented on GitHub (Sep 25, 2026):

Driver follow-ups committed on claude/compassionate-zhukovsky-279f1a:

b34ff37aa NE2K, AMDPCNet32II: timeouts fire only on a forward clock gap. NE2K's three ISR waits (NICGetISR(base) & 0x80 == 0) never ran because of operator precedence; they're parenthesised now, so the reset-ack and Tx RDC waits really poll. Boot-tested on a throwaway -snapshot guest: en0 comes up, pings work, 3× 1.49 MB transmits and a 2 MB receive all had matching checksums, with no timeout or reset messages on the console. AMDPCNet32II is not built: it already fails in its headers (if_ether.h:125/143, incomplete ea_hdr/ac_if), before reaching this change.
5d1d2f845 SerialPointingDevice: all three 40 ms dispatch gates also dispatch when currentTimeStamp < lastTimeStamp; recorded in reconstruction/divergences.md. Built; not tested with a serial mouse.

@raynorpat commented on GitHub (Sep 25, 2026): Driver follow-ups committed on `claude/compassionate-zhukovsky-279f1a`: - b34ff37aa **NE2K, AMDPCNet32II:** timeouts fire only on a forward clock gap. NE2K's three ISR waits (`NICGetISR(base) & 0x80 == 0`) never ran because of operator precedence; they're parenthesised now, so the reset-ack and Tx RDC waits really poll. Boot-tested on a throwaway `-snapshot` guest: en0 comes up, pings work, 3× 1.49 MB transmits and a 2 MB receive all had matching checksums, with no timeout or reset messages on the console. AMDPCNet32II is **not built**: it already fails in its headers (`if_ether.h:125/143`, incomplete `ea_hdr`/`ac_if`), before reaching this change. - 5d1d2f845 **SerialPointingDevice:** all three 40 ms dispatch gates also dispatch when `currentTimeStamp < lastTimeStamp`; recorded in `reconstruction/divergences.md`. Built; not tested with a serial mouse.

gitea-mirror commented

2026-11-03 22:02:30 -07:00

Author

Owner

@raynorpat commented on GitHub (Sep 25, 2026):

Merged to master in fe5c4d04e (local master; not yet pushed to origin): cd9fc5abd kernel clock fix, b34ff37aa NE2K/AMDPCNet32II guards (NE2K now 0.92 in 8f8a681fe), 5d1d2f845 SerialPointingDevice, and d585eea92 for the i386 toolchain profile. Still open: the i386 kernel with the clock fix has been built but not boot-tested, and the AMDPCNet32II header build break is being fixed separately.

@raynorpat commented on GitHub (Sep 25, 2026): Merged to master in fe5c4d04e (local master; not yet pushed to origin): cd9fc5abd kernel clock fix, b34ff37aa NE2K/AMDPCNet32II guards (NE2K now 0.92 in 8f8a681fe), 5d1d2f845 SerialPointingDevice, and d585eea92 for the i386 toolchain profile. Still open: the i386 kernel with the clock fix has been built but not boot-tested, and the AMDPCNet32II header build break is being fixed separately.

gitea-mirror referenced this issue

2026-11-03 22:04:29 -07:00

[PR #24] [MERGED] rbuild: ignore .hg directories when staging sources #83