Skip to content

Commit dfe003b

Browse files
committed
audio fix v2
1 parent 230a665 commit dfe003b

8 files changed

Lines changed: 298 additions & 29 deletions

File tree

‎PROJECT.md‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1216,6 +1216,14 @@ chatty renderer (~1250 draws, ~62 thousand COM calls per frame).
12161216
| `MOUSEAT=x,y[@frame,x,y]` | pin the cursor position the game sees (cursor mapping test) |
12171217
| `NOFOCUS=1` | open the window in the background, don't steal focus (testing while the user works) |
12181218
| `NOSOUND=1` | no sound output |
1219+
| `NFSU2_SLEEP_OLD=1` | the game's `Sleep`/timer back on `nanosleep` at default QoS, and every sound fix below off (issue #12 A/B) |
1220+
| `NFSU2_CATCHUP=0` | no timer catch-up / counted timer wake-ups / sleep debt |
1221+
| `NFSU2_PACE=0` | the sound loops read the virtual clock again (they stand still in long frames) |
1222+
| `NFSU2_GILPRIO=0` | no big-lock priority for the sound threads |
1223+
| `NFSU2_IOYIELD=0` | large file reads keep the big lock |
1224+
| `SLEEPSLACK=<us>` | measurement: every game `Sleep` / timer sleep wakes this much later |
1225+
| `GILHOG=<ms>:<ms>` | measurement: the game thread keeps the lock for the first value every second value, re-taking it every 50 us |
1226+
| `READSLOW=<us>` | measurement: every file read of 16 KB or more takes this much longer |
12191227
| `NORTFREE=1` | turn off releasing old render targets on Reset (diagnostic) |
12201228
| `NORTRESET=1` | don't return the target/Z to the back buffer on Reset (old behavior; the car breaks) |
12211229
| `NORSRESET=1` | don't reset render/sampler/stage states to defaults on Reset (old behavior) |
@@ -2204,3 +2212,39 @@ frame 1650); the headlight lenses are draws 213-222 (light atlas texture 813,
22042212
64x64, complete with 4 mips; 807 = tail lights); the highlight itself is the
22052213
scene's reflection on the body panels, not a missing texture and not post
22062214
processing. Not decided whether anything is wrong without a reference image.
2215+
2216+
## 2026-11-02 – 11-03: audio dropouts (issue #12)
2217+
2218+
Reports: the sound "is gone for a second" every few seconds, on several Macs, not
2219+
reproducible here. The reporter's log (M6, 60 Hz, NA HD): the sound service timer
2220+
ran at 32 ticks a second instead of 100, the music buffer got 130 KB/s for 176 KB/s
2221+
played, 28% of the output was silence, 99 cursor overruns, 8 s of silence while a
2222+
race loaded. The game's sound hangs on two 100 Hz loops: the DirectSound mixer thread
2223+
(`0x7263c7`, `THREAD_PRIORITY_TIME_CRITICAL`: `next += 10`, `Sleep(next - now)`) and
2224+
the sound service timer (`0x6f5b4d`, a one-shot `timeSetEvent` that re-arms itself
2225+
and `SetEvent`s the service thread, `THREAD_PRIORITY_HIGHEST`). Four causes, all in
2226+
`runtime/win32_ext.c` (+ `win32.c`, `fileio.c`, `dispatch.c`, `com.c`):
2227+
2228+
1. **Sleeps.** `Sleep` and the timer thread used `nanosleep`, which macOS coalesces,
2229+
and the game's threads ran at `QOS_CLASS_DEFAULT` (`pthread_create` does not
2230+
inherit QoS). Now `kevent NOTE_CRITICAL` and `USER_INTERACTIVE`. Under full CPU
2231+
load: late wake-ups 0.9 ms average / 25 ms max -> 0.03 / 2 ms.
2232+
2. **Late wake-ups lost ticks.** A timer re-armed for <= 1 ms (behind schedule)
2233+
fires again at once; a `SetEvent` from the timer thread counts (up to 16);
2234+
`Sleep` repays lateness (sleep debt). `SLEEPSLACK=55000`: 17 -> 100 ticks a
2235+
second, silence 9.7% -> 2.9% (2.7% without the slack).
2236+
3. **The virtual clock stood still in long frames** (50 ms cap), and so did both
2237+
loops. Their 7 clock reads (return addresses) now see real time and the timers
2238+
are due in real time (SOUND PACE CLOCK, `win32.c`). Large file reads also give
2239+
the big lock up.
2240+
4. **The big lock.** The macOS mutex is unfair; the game thread re-takes it thousands
2241+
of times a second. The sound threads (game priority >= 2) and the timer thread now
2242+
come first: others step back, the holder hands over at its next Win32, COM or
2243+
indirect call. Reproduced here: a 656 ms hold while a race loaded, 950 ms muted,
2244+
20 overruns (2 of ~12 runs); with priority the sound threads waited at most
2245+
10-24 ms, no dropouts in 5 runs, frame times unchanged.
2246+
2247+
The log now carries `[timer]` lines every 30 s (tick rate, late wake-ups, lock waits,
2248+
catch-up and lost ticks). Note for measurements: "sound data gaps" also counts the
2249+
silence of loading screens; use the stale guard and cursor overrun lines. Left: a
2250+
230-330 ms hold at start-up, before any sound plays (inaudible).

‎README.md‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -352,6 +352,13 @@ Yes, without Windows: `tools/install_from_discs.py` unpacks the disc images
352352
into a game folder. See [Installing from the PC discs on a
353353
Mac](#installing-from-the-pc-discs-on-a-mac).
354354

355+
**The sound cuts out for a moment every few seconds.**
356+
Fixed after v2.2: the game's two sound loops depend on waking up every 10 ms, and
357+
macOS woke them late or let the game's main thread keep them waiting (see
358+
`PROJECT.md`, "audio dropouts"). If it still happens, please attach
359+
`~/Library/Logs/NFSU2/nfsu2.log` (`nfsu2-hd.log` for HD) to an issue: its
360+
`[timer]` lines show which part is late.
361+
355362
**Does it work on Intel Macs?**
356363
No. Only Apple Silicon is targeted and tested.
357364

‎runtime/build_na.h‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -141,6 +141,13 @@
141141
#define GA_0x669fa6u 0x00669f96u /* function 00669f40 + 0x66 */
142142
#define GA_0x669fe5u 0x00669fd5u /* function 00669fc3 + 0x22 */
143143
#define GA_0x66d8afu 0x0066d89fu /* function 0066d7e9 + 0xc6 */
144+
#define GA_0x6f5b94u 0x006f5b94u /* function 006f5b4d + 0x47 */
145+
#define GA_0x6f5bacu 0x006f5bacu /* function 006f5b4d + 0x5f */
146+
#define GA_0x6f5da8u 0x006f5da8u /* function 006f5c91 + 0x117 */
147+
#define GA_0x7262b7u 0x007262b7u /* function 007260f7 + 0x1c0 */
148+
#define GA_0x7263d9u 0x007263d9u /* function 007263c7 + 0x12 */
149+
#define GA_0x726402u 0x00726402u /* function 007263c7 + 0x3b */
150+
#define GA_0x726411u 0x00726411u /* function 007263c7 + 0x4a */
144151
#define GA_0x7a66bcu 0x007a66b4u /* operand pair */
145152
#define GA_0x7b6fe8u 0x007b6fe0u /* operand pair */
146153
#define GA_0x7d7d3cu 0x007d7d3cu /* operand pair */

‎runtime/com.c‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2222,6 +2222,8 @@ static void tunedrag(unsigned char *ms){
22222222
int com_call(CPU *c, uint32_t magic){
22232223
uint32_t iface=(magic>>16)&0x1FFFu, m=magic&0xFFFFu;
22242224
g_com_calls++;
2225+
/* see win32_ext.c LOCK PRIORITY: a sound thread waiting for the big lock gets it here */
2226+
if (!g_sb_replay){ void guest_gil_check(void); guest_gil_check(); }
22252227
if (!g_sb_replay) POP32(c->eip);
22262228
if (iface==0 || iface>=NEL(g_if) || m>=g_if[iface].n){
22272229
fprintf(stderr," [COM] invalid interface/method %u:%u\n", iface, m);

‎runtime/dispatch.c‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
#include <stdatomic.h>
12
/* Indirect call dispatch: guest address -> lifted native function.
23
* O(1) direct index table (a uint32 array the size of .text). */
34
#include "cpu.h"
@@ -77,6 +78,11 @@ void dispatch_indirect(CPU *c, uint32_t addr){
7778
{ extern int g_efx_stat; extern void efx_stat_note(CPU *c, uint32_t addr);
7879
if (g_efx_stat && addr - 0x650000u < 0x40000u) efx_stat_note(c, addr); }
7980
uint32_t off = addr - TEXT_BASE;
81+
/* win32_ext.c LOCK PRIORITY: a waiting sound thread also gets the big lock here, so a
82+
* long stretch of game code without Win32 or COM calls (a load) doesn't keep it out */
83+
{ extern _Atomic int g_gil_prio_wait;
84+
if (__builtin_expect(atomic_load_explicit(&g_gil_prio_wait, memory_order_relaxed) != 0, 0)){
85+
void guest_gil_check(void); guest_gil_check(); } }
8086
if (off < TEXT_SIZE){
8187
uint32_t k = g_idx[off];
8288
if (k){

‎runtime/fileio.c‎

Lines changed: 20 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -332,9 +332,26 @@ static int fileio_call_impl(CPU *c, const char *n, uint32_t *out){
332332
else { if(len) mem_commit(buf,len);
333333
ssize_t got;
334334
uint64_t _rd0 = now_ns_io();
335+
/* READ WITHOUT THE BIG LOCK: a large read gives the big lock up while the disk
336+
* works. The game reads a race's data in multi-megabyte pieces on its main
337+
* thread; on a slow disk (external drive, files iCloud has to fetch back) the
338+
* sound threads couldn't run for the whole load and the music stopped (issue
339+
* #12 log: 8 s). On Windows the sound runs alongside. The buffer is the
340+
* game's own, as on Windows. NFSU2_IOYIELD=0 keeps the lock; READSLOW=<us>
341+
* (measurement) makes every large read that much slower, like a slow disk. */
342+
int io_y = 0;
343+
{ static int yoff = -1; if (yoff < 0){ const char *e = getenv("NFSU2_IOYIELD"); yoff = e && *e == '0'; }
344+
static long slow = -1; if (slow < 0){ const char *e = getenv("READSLOW"); slow = e ? atol(e) : 0; }
345+
if (len >= 16384u){
346+
int guest_blocking_begin(void);
347+
if (!yoff) io_y = guest_blocking_begin();
348+
if (slow > 0) usleep((useconds_t)slow);
349+
} }
350+
int fd = f->fd;
335351
if (ov && mem_is_committed(ov+19)){
336352
uint64_t off = (uint64_t)MR32(ov+8) | ((uint64_t)MR32(ov+12) << 32);
337-
got = pread(f->fd, g_mem+buf, len, (off_t)off);
353+
got = pread(fd, g_mem+buf, len, (off_t)off);
354+
if (io_y){ void guest_blocking_end(void); guest_blocking_end(); io_y = 0; }
338355
if(got<0) got=0;
339356
MR32(ov+0) = 0; /* Internal = STATUS_SUCCESS */
340357
MR32(ov+4) = (uint32_t)got; /* InternalHigh = bytes read */
@@ -351,9 +368,10 @@ static int fileio_call_impl(CPU *c, const char *n, uint32_t *out){
351368
} else if (f->empty){
352369
got = 0; /* immediate end of file */
353370
} else {
354-
got = read(f->fd, g_mem+buf, len);
371+
got = read(fd, g_mem+buf, len);
355372
if(got<0) got=0;
356373
}
374+
if (io_y){ void guest_blocking_end(void); guest_blocking_end(); io_y = 0; }
357375
/* MUTEFILE=<substring>: fill the reads of the matching file with ZEROS.
358376
* To measure objectively whether sound effects remain once the
359377
* music stream (sdat.viv) is silenced. We don't return end of

‎runtime/win32.c‎

Lines changed: 36 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -176,6 +176,41 @@ uint64_t host_us(void){
176176
return base + d + atomic_load(&g_vclock_creep);
177177
}
178178
uint32_t host_ms(void){ return (uint32_t)(host_us() / 1000ull) + 1000u; }
179+
180+
/* ---- SOUND PACE CLOCK ---------------------------------------------------------
181+
* The game's two 100 Hz sound loops time themselves with GetTickCount/timeGetTime:
182+
* the sound service timer (0x6f5b4d: due += 10 ms, re-arm for due - now - 1, seeded at
183+
* 0x6f5da6) and the DirectSound mixer thread (0x7263c7: next += 10 ms, Sleep(next -
184+
* now); its mixer measures the time since the last pass at 0x7262b1). The virtual
185+
* clock stops at 50 ms inside a frame, so in a long frame -- a load -- both loops saw
186+
* time stand still: the timer re-armed itself further and further out (10, 20, 30 ms
187+
* ...) and the mixer slept up to 200 ms per pass; the music stopped for the whole load
188+
* (issue #12 log: 8 s of silence while a race loaded). On Windows these loops run on
189+
* real time. Only these call sites (their return addresses) read real time, aligned
190+
* with the virtual clock at the first read; their values never meet the rest of the
191+
* game's time. NFSU2_PACE=0 turns it off. */
192+
int pace_on(void){
193+
static int on = -1;
194+
if (on < 0){ const char *e = getenv("NFSU2_PACE"), *o = getenv("NFSU2_SLEEP_OLD");
195+
on = !((e && *e == '0') || (o && *o == '1')); }
196+
return on;
197+
}
198+
static int pace_site(uint32_t ra){
199+
if (!pace_on()) return 0;
200+
return ra == GA(0x6f5b94u) || ra == GA(0x6f5bacu) || ra == GA(0x6f5da8u) || /* GetTickCount */
201+
ra == GA(0x7263d9u) || ra == GA(0x726402u) || ra == GA(0x726411u) || ra == GA(0x7262b7u); /* timeGetTime */
202+
}
203+
static uint32_t pace_ms(void){
204+
static _Atomic int64_t offset_us = INT64_MIN;
205+
int64_t o = atomic_load(&offset_us);
206+
if (o == INT64_MIN){
207+
int64_t want = (int64_t)host_us() - (int64_t)real_us();
208+
if (!atomic_compare_exchange_strong(&offset_us, &o, want)) o = atomic_load(&offset_us); else o = want;
209+
}
210+
return (uint32_t)((uint64_t)((int64_t)real_us() + o) / 1000ull) + 1000u;
211+
}
212+
uint64_t g_pace_reads = 0;
213+
uint32_t game_ms_at(uint32_t ra){ if (pace_site(ra)){ g_pace_reads++; return pace_ms(); } return host_ms(); }
179214
uint64_t host_qpc(void){ return host_us(); }
180215

181216
/* the guest heap itself lives in gheap.c (free lists + quarantine) */
@@ -424,7 +459,7 @@ int win32_call(CPU *c, uint32_t idx){
424459
else if (!strcmp(n,"GetCurrentProcess")) r = 0xffffffffu;
425460
else if (!strcmp(n,"GetLastError")) r = 0;
426461
else if (!strcmp(n,"SetLastError")) r = 0;
427-
else if (!strcmp(n,"GetTickCount")) r = host_ms();
462+
else if (!strcmp(n,"GetTickCount")) r = game_ms_at(c->eip); /* see SOUND PACE CLOCK */
428463
else if (!strcmp(n,"QueryPerformanceFrequency")){ uint32_t p=ARG(c,0); if(p){MR32(p)=1000000;MR32(p+4)=0;} r=1; }
429464
else if (!strcmp(n,"SetUnhandledExceptionFilter")) r = 0;
430465
else if (!strcmp(n,"UnhandledExceptionFilter")) r = 0;

0 commit comments

Comments
 (0)