From b9a7fc746603cf32372fe138e28d3dbf32e0529c Mon Sep 17 00:00:00 2001 From: SailorSnoW Date: Tue, 10 Nov 2026 21:15:26 +0100 Subject: [PATCH] =?UTF-8?q?Each=20nn::codec=20video=20decoder=20decodes=20?= =?UTF-8?q?on=20a=20thread=20of=20its=20own,=20and=20dav1d=20on=204=20thre?= =?UTF-8?q?ads=20with=203=20frames=20at=20once:=20a=20submission=20queues?= =?UTF-8?q?=20its=20packet=20and=20returns,=20as=20the=20SDK's=20does.=20D?= =?UTF-8?q?ecoded=20inside=20Submit=E2=80=A6InputBuffer,=20a=20packet=20he?= =?UTF-8?q?ld=20the=20client's=20thread=20for=20the=20whole=20decode;=20Oc?= =?UTF-8?q?arina=20of=20Time's=20movie=20reader,=20which=20also=20gives=20?= =?UTF-8?q?the=20shown=20pictures=20back,=20was=20held=20up=20to=20120=20m?= =?UTF-8?q?s,=20and=20its=20title=20movie=20(AV1,=201080p=20at=2060=20fps,?= =?UTF-8?q?=20dav1d=20on=20an=20M2=20Pro)=20showed=20a=20picture=20again?= =?UTF-8?q?=20in=20546=20and=20569=20of=20about=202,900=20frames=20at=20a?= =?UTF-8?q?=20steady=2060=20fps,=20now=20in=200=20or=201?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - hle_codec_video.c: cv_worker decodes the packets cv_dec_submit queues. The submission-ready event and the refusal count the pictures waiting for a released buffer, the packets queued and the one in decode together (cv_pending), so a client sees the same event whatever the decoder's speed. The decoder's thread waits for room instead of dropping a picture, and signals the sync point events itself. Stop and Flush drop the queued packets and number the stream anew, so the pictures of a packet still in decode are dropped; Finalize joins the thread. Guest calls take the decoder's lock as a host lock. One log line when a run of 600 packets left more released buffers waiting than the decoder has (`the decoder is behind the movie`), and the totals at Finalize - hle_movie_av1.c: dav1d on 4 threads, 3 frames at once (15.4 → 7.1 ms a packet over the title movie's heaviest five seconds, 122 → 42 to 76 ms the longest; more task threads on one frame gave nothing). Pictures come out later than their units, so each unit's time rides with its picture (mav1_picture.ts) and mav1_next gives the pictures after a unit, draining when no packet waits behind it or the stream ends. A drain that has given a picture goes to its end: dav1d 1.5.4's drain, left halfway by new data, retires a frame with task_thread.first past the oldest one and cancels a live frame's task rescan, and dav1d_submit_frame waits for ever (the title movie froze in 3 runs of 6 with a drain that stopped when a packet arrived) - t_codec_video.c: the event and the refusal with the packets decoded or not, which thread signals what, eight flushes with undecoded packets, a Finalize with undecoded packets, AV1 key frames through the protocol with their times in order, a mid-stream drain and 600 rounds of drains at random places - docs/reference/movies.md: `nn::codec` packets decoded inside the submission; dav1d decoded one frame at a time; the two entries they change. The Ocarina of Time note, a line in Kirby Air Riders' (the busy line's wording); symptom index regenerated Measured on an M2 Pro (Mac14,9, macOS 27.2.1), the title for 54 s, headless, the player's settings, DM_PROBE on the player's advance (main+0x3b61ed8 failed, main+0x3b61f80 good): before, 546 and 569 failed of about 2,900; after, 0 or 1 of 2,567 to 3,036 in ten runs, no frozen movie. DecodeAsync returns in 0.10 ms at the median and 1.1 ms at the 99th percentile, from 1.9 and 120 ms. In a window, 88 s of the title movie: 5,273 packets in 4.82 ms each, 2 pictures after their buffer. Checked: make -C dm/host/tests run and tsan-threads pass; t_codec_video also under ThreadSanitizer, five runs with no report; test_docs passes; the host builds with no new warning. Not checked: no regression run (the harness is not set up on this Mac, which has this game only), so Donkey Kong Bananza, Mario Kart World, Mario Tennis Fever, Kirby Air Riders and Fire Emblem Fortune's Weave were not run with it; an M1 or M2 with four performance cores and an iPad were not run; a Mac with a hardware AV1 decoder (VideoToolbox, where only the decoder's thread applies) was not measured. Co-Authored-By: Claude Fable 5.2 --- dm/games/0400486024DEC000/README.md | 5 +- dm/games/040077201BE50000/README.md | 2 +- dm/host/hle_codec_video.c | 241 +++++++++++++++++++++------- dm/host/hle_movie_av1.c | 92 ++++++++--- dm/host/hle_movie_av1.h | 14 +- dm/host/tests/t_codec_video.c | 109 ++++++++++--- docs/agents/symptoms.md | 2 + docs/reference/movies.md | 29 +++- 8 files changed, 376 insertions(+), 118 deletions(-) diff --git a/dm/games/0400486024DEC000/README.md b/dm/games/0400486024DEC000/README.md index f14f410248..979c60d8e5 100644 --- a/dm/games/0400486024DEC000/README.md +++ b/dm/games/0400486024DEC000/README.md @@ -33,6 +33,7 @@ Measured on an M6 Mac with 16 GB, headless, on one walk with camera turns (`walk - Current on an M5 Pro MacBook Pro (16-inch, 20-core GPU, 24 GB, macOS 27.2, 2026-11-09), `kokiri-deck` from a deck autosave with the full library of chain `dedc9391c30b`, at full resolution (Dynamic resolution off), two runs a variant: in a window a locked 60 fps (59.8–60.0, frame p99 16.8–19.4 ms, GPU p50 10.2 ms). In fullscreen on its ProMotion screen it held 40 fps (39.6–40.1) at the same GPU time, with every present a 120 Hz refresh late and every other link tick skipped: [The 60 Hz link at 40 fps in fullscreen on a ProMotion screen](../../../docs/reference/frame-rate.md#the-60-hz-link-at-40-fps-in-fullscreen-on-a-promotion-screen). With the 120 Hz link there, 58.8–59.6 fps, frame p99 25.3 ms; with the screen held at its fixed 60 Hz mode, 60.0 fps, frame p99 16.9 ms, which fullscreen now switches to. MetalFX present upscaling to the 3456-wide fullscreen cost no measurable GPU time (59.4–59.7 fps). Resident about 10 GB, GPU allocated 11.2–11.4 GB; the prepare step took 7.3 s on a first start. - Current: the title and menu, a movie behind them, are a locked 60 fps (p50 16.67 ms, GPU span 15.6 ms). +- Resolved: the title movie and the cutscene movies stuttered in small regular jerks at that steady 60 fps on a Mac that decodes AV1 with dav1d (M1, M2). The frames were on time and the movie's pictures were not: the player's `advance` (`main+0x3b61ea0`) found no new picture in 546 and 569 of about 2,900 frames of the title on an M2 Pro, and showed the last one again. Two causes, both general: [packets decoded inside the submission](../../../docs/reference/movies.md#nncodec-packets-decoded-inside-the-submission), on the player's one reader thread, which also gives the shown pictures back, and [dav1d one frame at a time](../../../docs/reference/movies.md#dav1d-decoded-one-frame-at-a-time) (15.4 ms a packet in the movie's heaviest five seconds, 122 ms the longest). After: 0 or 1 in 2,567 to 3,036 frames a run (eight runs of 54 s, headless, `DM_PROBE=main:3b61ed8,main:3b61f80` counting the failed and the good calls), and `DecodeAsync` returns in 0.1 ms at the median and 1.1 ms at the 99th percentile, from 1.9 and 120 ms. Open: not run on an M1 or M2 with four performance cores, nor on an iPad; a Mac with a hardware AV1 decoder (M3 on) decodes with VideoToolbox, where only the first cause applied, not measured. - Game speed: the game steps its time by a frame ratio, its base rate (60, or 30) / its int frame rate, whatever the frame took (`main+0x6e6cc4` on v131072), so frames longer than a vsync played in slow motion (seen by the user on a slower Mac; [issue 1375](https://github.com/seedds/nxnative/issues/1375)'s M1 Max ran the title at about 28 fps). With `fps_target 60` the ratio is the host's frame step × base / 60 ([A fixed frame step plays in slow motion on a slow Mac](../../../docs/reference/frame-rate.md#a-fixed-frame-step-plays-in-slow-motion-on-a-slow-mac)), a stub placed by its function's fingerprint ([`patches.py`](patches.py)). Mac runs on the M6 (2026-11-08, a test host on the libraries of chain `3ee493b2c3a4`): the user's play sessions held 60 fps with 2- and 3-vsync holds while areas loaded, game time 1.000 of real time by the host's count. That count is the stub's own; no run on a Mac slow enough to show the slow motion before and after. - Current: walking the village at the game's top internal resolution, 1536x864: a locked 60 fps, mean 16.67 ms over each settled window. Per 2,700 frames: 0-8 frames over 25 ms and 0-2 over 33 ms. Frame p95 17.8-18.9 ms with no window, as the game's own loop moves around its fence wait; in a window p95 17.8 ms, 3 over 25 ms and 5-16 over 18 ms per 600. GPU span p50 16.5 ms, summed GPU 15.8 ms, CPU 6 ms, about 101 passes a frame. The heavy stretch where the village opens (about 1,560 draws) holds 16.65-16.8 ms by lowering its resolution, then returns to full. The main pass used to sit at 763x429 at the same GPU time: [marked shaders tested depth late](../../../docs/reference/frame-rate.md#a-hosts-own-store-in-a-fragment-shader-moves-its-depth-test). - Before [pool shaders stopped counting as depth readers](../../../docs/reference/rendering.md#pool-shaders-taken-as-depth-readers): passes 118, 104, 219, 224 in a four-frame cycle, frame times 15, 15, 18, 18.5 ms, mean 16.9 ms. Half the frames rendered the reflection probe's faces with one draw a pass. @@ -103,7 +104,7 @@ From an empty save: at about 45 s `A` (title), `A` (New Game), then the movie. F - Resolved in the log, to be eye-checked at the spots it showed: flat blue holes in the ground with grass and rocks floating over them (Kokiri Forest, the village floor, the Deku Tree) after an hour of play: [textures made for GPU use kept from their CPU rewrites](../../../docs/reference/nvn-objects.md#textures-made-for-gpu-use-kept-from-their-cpu-rewrites). The terrain tiles' height, blend and hole maps are rewritten from the CPU as tile slots are reused, and the dirty-page poll dropped every uncompressed one; with the fix, about 250 of them upload in the first 160 s of the Kokiri Forest autosave and a walk onto the village floor (M4 Pro), and the normal tiles the GPU draws stay, or become again, the GPU's. - Open, small differences from that same console frame: Navi's core has a harder edge and a narrower glow here (the bloom texture peaks at 0.44; the ball's HDR is about 0.9 with a tiny spot at 45); shadows are less blue, and the far grass about 1.4 times brighter. One frame of compressed video is weak evidence for either. The falling leaves look dark near the camera, not compared. - A red `texture type mismatch` on `9b310b3349825e9a` (a UI merge shader): a 3D texture left bound in a slot its active branch does not sample. Harmless so far. -- `nn::codec AV1: busy (result 3603), a packet refused with 12 pictures waiting` (4 lines a run): the decoder's queue is full and the movie library retries, as it is written to ([a refusal is no fault](../../../docs/reference/movies.md#the-submission-ready-event-counted-as-packets)); movies play. It was a red line until then. +- `nn::codec AV1: busy (result 3603), a packet refused with 0 pictures waiting for a released buffer and 12 packets to decode` (4 lines a run, at the title movie's start, where the reader sends ahead of the decoder): the decoder's queue is full and the movie library retries, as it is written to ([a refusal is no fault](../../../docs/reference/movies.md#the-submission-ready-event-counted-as-packets)); movies play. It was a red line until then. - The `pipeline archive` red line is [issue 342](https://github.com/seedds/nxnative/issues/342), a limit of this system build. `c1_full.tsv is stale` holds on partial libraries, which no full build has stamped. - The "Navi" name label in the Great Deku Tree scene was missing on an earlier chain and has not been checked since. Not played yet: the Deku Tree dungeon, combat, later areas. Sound opens with no red line; movies and speech were not listened to. Physics issues reported in PR 1299 were not seen on this route (walking, the ladder, the camera). - Resolved: dotted horizontal rows across the picture in play, in fog and light (GitHub issue 1537): the agl_ndsr_vr networks' HMMA calls outside a chain overwrote an accumulator a chain held ([An HMMA outside a chain overwrote the chain's accumulator](../../../docs/reference/shaders.md#an-hmma-outside-a-chain-overwrote-the-chains-accumulator)), since chain 23a1ea1db092; found by bisecting chains on the Kokiri Forest autosave (0f510fd5's chain clean, bd9f422d's not). Under the game's upscaler they had also grown into white blotches: [LDSM reads rows other lanes stored](../../../docs/reference/shaders.md#ldsm-reads-rows-other-lanes-stored). @@ -205,5 +206,7 @@ From an empty save: at about 45 s `A` (title), `A` (New Game), then the movie. F - [Pixel shader inputs the mesh shader does not write](../../../docs/reference/shaders.md#pixel-shader-inputs-the-mesh-shader-does-not-write): the foliage point meshes' pipelines (pixel shaders reading generic attribute 5 that no mesh output writes). - [Mesh outputs as wide as their pixel shaders read](../../../docs/reference/shaders.md#mesh-outputs-as-wide-as-their-pixel-shaders-read): the foliage mesh `626fbf48041cb82b`, padded to 35,840 bytes of mesh output, past Metal's 32 KB. - [AV1 movies stop an M1 iPad with SIGILL in dav1d](../../../docs/reference/movies.md#av1-movies-stop-an-m1-ipad-with-sigill-in-dav1d): the title movie on an M1 iPad Pro. +- [`nn::codec` packets decoded inside the submission](../../../docs/reference/movies.md#nncodec-packets-decoded-inside-the-submission): resolved, movies stuttering at a steady 60 fps; its player feeds the decoder and gives the shown pictures back on one thread. +- [dav1d decoded one frame at a time](../../../docs/reference/movies.md#dav1d-decoded-one-frame-at-a-time): resolved, the title movie's heavy packets on an M2 Pro; and the drain that must go to its end. - [`devicectl` copies a large RomFS image through the Mac's memory](../../../docs/reference/packing.md#devicectl-copies-a-large-romfs-image-through-the-macs-memory): the 26.2 GB image's pushes to an iPad filled a 16 GB Mac's swap and failed; now sent over AFC. - [`devicectl`'s `--remove-existing-content` empties the app's whole container](../../../docs/reference/packing.md#devicectls---remove-existing-content-empties-the-apps-whole-container): the first complete copy of the image, deleted by the DLC step after it. diff --git a/dm/games/040077201BE50000/README.md b/dm/games/040077201BE50000/README.md index f72faa6da5..4bcf6c0268 100644 --- a/dm/games/040077201BE50000/README.md +++ b/dm/games/040077201BE50000/README.md @@ -55,7 +55,7 @@ Moving objects get their ambient light from eight values per object in a storage - A crash seen once in dozens of runs, in a run slowed by another game on the same GPU: the game's own wait at `main+0x2ecff24` (`ldarb` on a thread object at +0x285, in a loop that sleeps between reads) read an alias page just unmapped, right after `[mem] alias region mapped` fell. Not caused by the host's page protection, which does not unmap; whether the host unmaps earlier than Horizon would is not known. - The 12x12 cube the vertex shader mixes with the probe values holds 4 to 27 with `tex_flush_upload`, and read zeros without it. - [The guard band cull's](../../../docs/reference/shaders.md#a-guard-band-cull-in-every-vertex-shader-0x80d) real meaning, and the vertex output at `a[0x5c]` that 4,771 vertex shaders write and the translator drops (probably a shading rate, not checked). -- `nn::codec VP9: busy (result 3603), a packet refused with 12 pictures waiting for a released buffer` (4 lines at the first movie, a red line until [a refusal was known to be no fault](../../../docs/reference/movies.md#the-submission-ready-event-counted-as-packets)); the movies seen play. +- `nn::codec VP9: busy (result 3603), a packet refused with 12 pictures waiting for a released buffer` (4 lines at the first movie; since [the decoder has its own thread](../../../docs/reference/movies.md#nncodec-packets-decoded-inside-the-submission) the line also counts the packets still to decode, not seen on this game yet; a red line until [a refusal was known to be no fault](../../../docs/reference/movies.md#the-submission-ready-event-counted-as-packets)); the movies seen play. - A `pso_manifest.tsv` has not been recorded, so the first race compiles pipelines as it goes. - What `nvnTextureViewCompare`'s return value means is taken from its name. - City Trial played by hand, Road Trip, online, the base game, iOS: not tested. diff --git a/dm/host/hle_codec_video.c b/dm/host/hle_codec_video.c index d9a4c070bf..4b73dec547 100644 --- a/dm/host/hle_codec_video.c +++ b/dm/host/hle_codec_video.c @@ -8,8 +8,11 @@ // then reads the picture's properties (description 3604 until it is filled) and the picture (ReadDecoderOutputImageRgba / Nv12, the CPU route; Bananza's player takes that one) // - SubmitVp9DecoderInputBuffer takes one packet with its time and an end-of-stream flag; description 3603 when the decoder cannot take more (the client retries after the // submission-ready event). -// Pictures go into the released buffers in release order. Packets decode on the submitting thread; pictures with no released buffer to go into wait in a short queue, and a full -// queue refuses packets. The SDK's opaque types hold a host pointer at +0 (pool: 0x20 bytes are the SDK's; decoder: 0x400), the decoder's event lives in its type at +0x100. +// Pictures go into the released buffers in release order. A submission queues its packet and returns, as the SDK's does (its decoder is another process): each decoder decodes on +// a thread of its own (cv_worker). Decoded inside the submission, a heavy packet held the client's thread for the whole decode, and that thread is the one that gives shown +// pictures back and takes decoded ones: Ocarina of Time's movie reader was held 30 ms and more once per group of pictures of its 1080p 60 fps AV1 title movie (dav1d), the game +// found its shown picture not yet given back, and repeated it for a frame or two. Pictures with no released buffer to go into wait in a short queue, and packets are refused +// once packets and pictures waiting fill it. The SDK's opaque types hold a host pointer at +0 (pool: 0x20 bytes are the SDK's; decoder: 0x400), the decoder's event lives in its type at +0x100. // VP8, VP9, H.264 and AV1 decoders share it all (cv_dec_*). Not served: encrypted input and alias pools. // SDK 22 (Fire Emblem Fortune's Weave's movie module, subsdk2) reaches the same protocol through other names: ByTransferMemory / ByRemoteMemory initializers, a preference with an image tiling mode, // a pool without its mode, and a submission event returned rather than written out. Its player can take pictures the GPU route: GetDecoderImagePoolNativeImageHandle's handle goes through @@ -27,9 +30,10 @@ #define CV_MAGIC 0x56436d44u // 'DmCV' #define CV_SYNC 0x53436d44u // 'DmCS': a sync handle the host made (dec id, index, generation) #define CV_BUFS 32 -#define CV_READY 4 // decoded pictures waiting for a released buffer at which the submission-ready event goes down +#define CV_READY 4 // packets and decoded pictures waiting (cv_pending) at which the submission-ready event goes down #define CV_HOLD 12 // and at which packets are refused. Mario Tennis Fever's player sends one packet per signal and ignores the result (nro0+0xd16130), so a signal in flight when the // event goes down must still find room: refused at 4, a packet about 6 s into the title movie was lost, and libvpx found every frame after it corrupt +#define CV_STAT 600 // packets between two looks at the decode times (cv_stat) #define CV_EVENT_OFF 0x100 // the submission-ready SystemEventType inside the decoder type #define CV_R(desc) ((Result)(0x6f | ((desc) << 9))) // nn::codec results (module 111) #define CV_BUSY CV_R(3603) // the decoder cannot take the packet now @@ -38,6 +42,7 @@ typedef struct { uint16_t w, h; uint32_t fmt, mode, magic; uint32_t pad[2]; } cv_pref; // VideoDecoderImagePreference as the host fills it (returned in x8) typedef struct { uint32_t magic; uint16_t w, h; uint32_t fmt, count; vpx_image_t **img; uint8_t *mem; uint64_t size; int slot; _Atomic int native; } cv_pool; // mem, size: the game's pool memory; native: a handle was asked for (RGBA kept in mem); slot: its place in g_cv_pools + 1 typedef struct { uint32_t magic, dec, idx, gen; } cv_sync; // nn::gs::NativeSyncHandle (16 bytes) +typedef struct { uint64_t n, ns, max, late; } cv_times; // packets decoded, their time in all and the longest; late: pictures whose buffer was released before they were decoded enum { CV_VP8, CV_VP9, CV_H264, CV_AV1 }; static const char *const k_cv_name[] = {"VP8", "VP9", "H.264", "AV1"}; typedef struct { @@ -49,10 +54,17 @@ typedef struct { uint32_t pend[CV_BUFS], phead, pcount; // released, waiting for a picture vpx_image_t *held[CV_HOLD]; int64_t held_ts[CV_HOLD]; uint8_t held_eos[CV_HOLD]; int nheld; int eos_pending; + // The decoder's thread (cv_worker). The codec state above (vpx, avc, av1) is its own from Initialize to Finalize: it decodes outside mu + pthread_t th; pthread_cond_t work; // work: a packet was queued, room for pictures came back, a Stop / Flush or Finalize came + int quit, busy, reopen; // busy: the thread decodes a packet; reopen: a Stop / Flush came, so it makes a new codec state before its next packet + uint32_t epoch; // counts Stop / Flush: the pictures of a packet taken before one are dropped + struct { uint8_t *data; uint64_t size; int64_t ts; uint8_t eos; } q[CV_HOLD]; uint32_t qhead, qcount; // the packets taken and not yet decoded, in order (copies) + cv_times st, all; // decode times of the current run of CV_STAT packets and of the runs before it } cv_dec; static cv_dec *g_cv[16]; -static pthread_mutex_t g_cv_mu = PTHREAD_MUTEX_INITIALIZER; // lock order: g_cv_mu, then a decoder's mu, then g_spt_mu +static pthread_mutex_t g_cv_mu = PTHREAD_MUTEX_INITIALIZER; // lock order: g_cv_mu, then a decoder's mu, then g_spt_mu. A decoder's thread holds its mu while it writes a picture into a buffer + // (a conversion to RGBA for a native image), so the client's threads take both with dm_host_mutex_lock: waiting, they are blocked static cv_dec *cv_of(void *t) { cv_dec *d = t ? *(cv_dec **)t : NULL; return d && d->magic == CV_MAGIC ? d : NULL; } static cv_pool *pool_of(const void *t) { cv_pool *p = t ? *(cv_pool *const *)t : NULL; return p && p->magic == CV_MAGIC ? p : NULL; } @@ -99,11 +111,11 @@ static void pool_native_write(cv_pool *p, uint32_t i, const vpx_image_t *im) { for (uint32_t y = 0; y < p->h; y++) memcpy(dst + (size_t)y * stride, tmp + (size_t)y * p->w * 4, (size_t)p->w * 4); free(tmp); } -// Pictures and end of stream into the released buffers, in order (decoder lock held). The event says a packet can come: it rises when one was taken (took) or room came back, not at every release. -// Mario Tennis Fever's player counts each signal as one packet it may send: raised at every release, its count grew while a seek held back the samples (a skipped cutscene), -// and the packets it then sent overran CV_HOLD -static void drain(cv_dec *d, int took) { - int before = d->nheld; +static int cv_pending(const cv_dec *d) { return d->nheld + (int)d->qcount + d->busy; } // what the decoder holds for the client: packets not yet decoded and pictures no released buffer has taken (decoder lock held) +// Pictures and end of stream into the released buffers, in order (decoder lock held). decoded: the decoder's thread calls, with the pictures of the packet it has just decoded: +// a buffer they go into was waiting for them +static void fill(cv_dec *d, int decoded) { + int had = d->nheld; while (d->pcount && (d->nheld || d->eos_pending)) { uint32_t i = d->pend[d->phead]; d->phead = (d->phead + 1) % CV_BUFS; d->pcount--; typeof(d->buf[0]) *b = &d->buf[i]; @@ -114,12 +126,39 @@ static void drain(cv_dec *d, int took) { b->w = (uint16_t)im->d_w; b->h = (uint16_t)im->d_h; b->ts = ts; b->eos = eos; if (b->pool && b->pidx < b->pool->count) { pool_native_write(b->pool, b->pidx, im); if (b->pool->img[b->pidx]) vpx_img_free(b->pool->img[b->pidx]); b->pool->img[b->pidx] = im; } else vpx_img_free(im); if (!d->pictures++) LOG("[codec] %s decoder %u: first picture %ux%u into buffer %u", k_cv_name[d->codec], d->id, b->w, b->h, i); + if (decoded) d->st.late++; } else { b->w = b->h = 0; b->ts = 0; b->eos = 1; d->eos_pending = 0; } if (b->eos) LOG("[codec] %s decoder %u: end of stream after %llu pictures", k_cv_name[d->codec], d->id, (unsigned long long)d->pictures); b->filled = 1; b->filled_gen = b->gen; spt_fire(d, i); } - if (d->event) { if (d->nheld >= CV_READY) hle_clear_system_event(d->event); else if (took || before >= CV_READY) hle_signal_system_event(d->event); } + if (had >= CV_HOLD && d->nheld < CV_HOLD) pthread_cond_signal(&d->work); // the decoder's thread waited for room for its next packet's pictures +} +// The event says a packet can come: it rises when one was taken (took) or room came back (before: cv_pending before the change), not at every release (decoder lock held). +// Mario Tennis Fever's player counts each signal as one packet it may send: raised at every release, its count grew while a seek held back the samples (a skipped cutscene), +// and the packets it then sent overran CV_HOLD +static void ready(cv_dec *d, int before, int took) { + if (!d->event) return; + if (cv_pending(d) >= CV_READY) hle_clear_system_event(d->event); else if (took || before >= CV_READY) hle_signal_system_event(d->event); +} +// Decode times, for a movie that stutters at a steady frame rate: a decoder slower than the movie leaves the client's released buffers waiting for pictures (late), and the +// client shows a picture again. One line for a run of CV_STAT packets with more late pictures than its start explains (the buffers released before the first picture wait for +// it: the registered ones at most, and a Stop or Flush begins a new run), and one at Finalize. Ocarina of Time's title movie on an M2 Pro: 0 to 3 in a run with the decoder +// ahead, 29 and 18 in the two heaviest with dav1d on one frame at a time, where the player showed 5 to 7 pictures twice +static void cv_stat_line(const cv_dec *d, const cv_times *s, const char *what) { + LOG("[codec] %s decoder %u: %s%llu packets decoded in %.2f ms each, %.2f ms the longest; %llu pictures came after their buffer was released", k_cv_name[d->codec], d->id, what, + (unsigned long long)s->n, s->n ? (double)s->ns / 1e6 / (double)s->n : 0.0, (double)s->max / 1e6, (unsigned long long)s->late); +} +static void cv_stat_sum(cv_dec *d) { // the current run joins the earlier ones + d->all.n += d->st.n; d->all.ns += d->st.ns; d->all.late += d->st.late; if (d->st.max > d->all.max) d->all.max = d->st.max; + memset(&d->st, 0, sizeof d->st); +} +static void cv_stat(cv_dec *d, uint64_t dt) { // one packet took dt (decoder lock held) + d->st.n++; d->st.ns += dt; if (dt > d->st.max) d->st.max = dt; + if (d->st.n < CV_STAT) return; + uint64_t reg = 0; for (int i = 0; i < CV_BUFS; i++) reg += (uint64_t)d->buf[i].reg; + if (d->st.late > reg) cv_stat_line(d, &d->st, "the decoder is behind the movie: of the last "); + cv_stat_sum(d); } HLE_FORCE("_ZN2nn5codec5video10InitializeEv", "the decoder service is the host's (hle_codec_video.c)", Result, h_cv_init, void) { return 0; } @@ -151,8 +190,8 @@ HLE_FORCE("_ZN2nn5codec26InitializeDecoderImagePoolEPNS0_25VideoDecoderImagePool Result, h_cv_pool22, void *t, void *mem, uint64_t size, const cv_pref *p, uint32_t n) { return cv_pool_init(t, mem, size, p, n); } HLE_FORCE("_ZN2nn5codec24FinalizeDecoderImagePoolEPNS0_25VideoDecoderImagePoolTypeE", "frees the host pool", void, h_cv_poolfin, void *t) { cv_pool *p = pool_of(t); if (!p) return; - pthread_mutex_lock(&g_cv_mu); // a decoder still holding a buffer of this pool keeps it, with no pool to write its picture into - for (int k = 0; k < 16; k++) if (g_cv[k]) { pthread_mutex_lock(&g_cv[k]->mu); for (int i = 0; i < CV_BUFS; i++) if (g_cv[k]->buf[i].pool == p) g_cv[k]->buf[i].pool = NULL; pthread_mutex_unlock(&g_cv[k]->mu); } + dm_host_mutex_lock(&g_cv_mu); // a decoder still holding a buffer of this pool keeps it, with no pool to write its picture into + for (int k = 0; k < 16; k++) if (g_cv[k]) { dm_host_mutex_lock(&g_cv[k]->mu); for (int i = 0; i < CV_BUFS; i++) if (g_cv[k]->buf[i].pool == p) g_cv[k]->buf[i].pool = NULL; pthread_mutex_unlock(&g_cv[k]->mu); } if (p->slot) g_cv_pools[p->slot - 1] = NULL; pthread_mutex_unlock(&g_cv_mu); for (uint32_t i = 0; i < p->count; i++) if (p->img[i]) vpx_img_free(p->img[i]); @@ -161,7 +200,7 @@ HLE_FORCE("_ZN2nn5codec24FinalizeDecoderImagePoolEPNS0_25VideoDecoderImagePoolTy HLE_FORCE("_ZN2nn5codec36GetDecoderImagePoolNativeImageHandleEPKNS0_25VideoDecoderImagePoolTypeEj", "a handle the host's nvnNativeImage knows; the pool keeps its pictures as RGBA from now on", uint32_t, h_cv_native, const void *t, uint32_t i) { cv_pool *p = pool_of(t); if (!p || i >= p->count) return 0; - pthread_mutex_lock(&g_cv_mu); + dm_host_mutex_lock(&g_cv_mu); if (!p->slot) for (int k = 0; k < 256; k++) if (!g_cv_pools[k]) { g_cv_pools[k] = p; p->slot = k + 1; break; } pthread_mutex_unlock(&g_cv_mu); if (!p->slot) { static int once; if (!once++) LOG("[RED] nn::codec: more than 256 pools with native images"); return 0; } @@ -177,7 +216,7 @@ uint32_t dm_native_image_blank(uint32_t w, uint32_t h) { // a blank image's ha uint64_t size = ((uint64_t)blank_stride(w) * h + CV_NATIVE_ALIGN - 1) & ~(CV_NATIVE_ALIGN - 1); void *mem = size ? mmap(NULL, size, PROT_READ | PROT_WRITE, MAP_PRIVATE | MAP_ANON, -1, 0) : MAP_FAILED; if (mem == MAP_FAILED) return 0; - pthread_mutex_lock(&g_cv_mu); + dm_host_mutex_lock(&g_cv_mu); uint32_t k = 0; while (k < BLANK_MAX && g_blank[k].mem) k++; if (k < BLANK_MAX) { g_blank[k].w = w; g_blank[k].h = h; g_blank[k].mem = mem; g_blank[k].size = size; } pthread_mutex_unlock(&g_cv_mu); @@ -187,7 +226,7 @@ uint32_t dm_native_image_blank(uint32_t w, uint32_t h) { // a blank image's ha void dm_native_image_blank_free(uint32_t handle) { // a texture on it must be finalized first, as on the console uint32_t k = (handle & 0x7fffffffu) - 1; if (!(handle >> 31) || k >= BLANK_MAX) return; - pthread_mutex_lock(&g_cv_mu); + dm_host_mutex_lock(&g_cv_mu); uint8_t *mem = g_blank[k].mem; uint64_t size = g_blank[k].size; memset(&g_blank[k], 0, sizeof g_blank[k]); pthread_mutex_unlock(&g_cv_mu); if (mem) munmap(mem, size); @@ -195,7 +234,7 @@ void dm_native_image_blank_free(uint32_t handle) { // a texture on it must be // A native image handle's picture for hle_nvn.c: 1 and its memory, size and layout; 0 for a handle no pool or blank image holds int dm_native_image(uint32_t handle, uint8_t **mem, uint64_t *size, uint32_t *w, uint32_t *h, uint32_t *stride) { uint32_t slot = handle >> 8, i = handle & 0xff; int ok = 0; - pthread_mutex_lock(&g_cv_mu); + dm_host_mutex_lock(&g_cv_mu); uint32_t k = (handle & 0x7fffffffu) - 1; if (handle >> 31 && k < BLANK_MAX && g_blank[k].mem) { *mem = g_blank[k].mem; *size = g_blank[k].size; *w = g_blank[k].w; *h = g_blank[k].h; *stride = blank_stride(g_blank[k].w); @@ -248,16 +287,20 @@ static void cv_open(cv_dec *d) { // (re)creates the codec state: a new stream d->vpx_ok = vpx_codec_dec_init(&d->vpx, d->codec == CV_VP8 ? vpx_codec_vp8_dx() : vpx_codec_vp9_dx(), &cfg, 0) == VPX_CODEC_OK; if (!d->vpx_ok) LOG("[RED] nn::codec %s decoder: libvpx init failed", k_cv_name[d->codec]); } +static void *cv_worker(void *arg); static Result cv_dec_init(void *t, int codec, uint16_t w, uint16_t h, uint32_t in, uint32_t out, const void *csd, uint64_t csd_n) { cv_dec *d = calloc(1, sizeof *d); - d->magic = CV_MAGIC; d->codec = codec; d->w = w; d->h = h; pthread_mutex_init(&d->mu, NULL); + d->magic = CV_MAGIC; d->codec = codec; d->w = w; d->h = h; pthread_mutex_init(&d->mu, NULL); pthread_cond_init(&d->work, NULL); if (csd && csd_n && csd_n < (1u << 20)) { d->csd = malloc((size_t)csd_n); memcpy(d->csd, csd, (size_t)csd_n); d->csd_n = (size_t)csd_n; } cv_open(d); - pthread_mutex_lock(&g_cv_mu); + dm_host_mutex_lock(&g_cv_mu); for (int i = 0; i < 16; i++) if (!g_cv[i]) { g_cv[i] = d; d->id = (uint32_t)i + 1; break; } pthread_mutex_unlock(&g_cv_mu); if (!d->id) die("nn::codec: more than 16 video decoders"); d->event = (uint8_t *)t + CV_EVENT_OFF; hle_bind_system_event(d->event, 0); hle_signal_system_event(d->event); + pthread_attr_t a; pthread_attr_init(&a); pthread_attr_setstacksize(&a, 1 << 20); // libvpx decodes on it, as on the movie decoder's thread (hle_movie.c) + if (pthread_create(&d->th, &a, cv_worker, d)) die("nn::codec: cannot start a video decoder's thread"); + pthread_attr_destroy(&a); *(cv_dec **)t = d; LOG("[codec] %s decoder %u: %ux%u, input format %u, output format %u%s (%s on the host)", k_cv_name[codec], d->id, w, h, in, out, d->csd_n ? ", with parameter sets" : "", codec == CV_AV1 ? mav1_backend(d->av1) : codec == CV_H264 ? "VideoToolbox" : "libvpx"); @@ -265,22 +308,26 @@ static Result cv_dec_init(void *t, int codec, uint16_t w, uint16_t h, uint32_t i } static Result cv_dec_fin(void *t) { cv_dec *d = cv_of(t); if (!d) return 0; - pthread_mutex_lock(&g_cv_mu); g_cv[d->id - 1] = NULL; pthread_mutex_lock(&d->mu); pthread_mutex_unlock(&d->mu); pthread_mutex_unlock(&g_cv_mu); // no sync handle lookup is still inside + dm_host_mutex_lock(&g_cv_mu); g_cv[d->id - 1] = NULL; dm_host_mutex_lock(&d->mu); d->quit = 1; pthread_cond_signal(&d->work); pthread_mutex_unlock(&d->mu); pthread_mutex_unlock(&g_cv_mu); // no sync handle lookup is still inside + dm_host_thread_join(d->th, NULL); // a packet it decodes ends first (a codec cannot be stopped inside one); its pictures are dropped + cv_stat_sum(d); + if (d->all.n) cv_stat_line(d, &d->all, ""); if (d->codec != CV_H264 && d->codec != CV_AV1 && d->vpx_ok) vpx_codec_destroy(&d->vpx); if (d->avc) mavc_free(d->avc); if (d->av1) mav1_free(d->av1); for (int i = 0; i < d->nheld; i++) vpx_img_free(d->held[i]); + for (uint32_t k = 0; k < d->qcount; k++) free(d->q[(d->qhead + k) % CV_HOLD].data); free(d->csd); d->magic = 0; // The submission-ready event goes with the decoder, as in the SDK. Kept, it stayed in the host's bound-event table, so the next decoder initialised in the same memory found its // event "bound" and was not given one: the game had cleared that memory, and nn::os aborted on the uninitialised event (Donkey Kong Bananza, its second movie) static void (*destroy)(void *); if (!destroy && !(destroy = guest_sym("_ZN2nn2os18DestroySystemEventEPNS0_15SystemEventTypeE"))) die("nn::os::DestroySystemEvent missing"); destroy(d->event); - pthread_mutex_destroy(&d->mu); free(d); *(cv_dec **)t = NULL; + pthread_cond_destroy(&d->work); pthread_mutex_destroy(&d->mu); free(d); *(cv_dec **)t = NULL; return 0; } static Result cv_dec_reg(void *t, uint32_t i, void *pool, uint32_t pidx) { cv_dec *d = cv_of(t); if (!d || i >= CV_BUFS) { LOG("[RED] nn::codec::Register…DecoderBuffer index %u", i); return CV_R(2004); } - pthread_mutex_lock(&d->mu); + dm_host_mutex_lock(&d->mu); d->buf[i].pool = pool_of(pool); d->buf[i].pidx = pidx; d->buf[i].reg = 1; d->buf[i].filled = 0; d->buf[i].gen = 0; d->buf[i].filled_gen = 0; if (d->fcount < 8) { d->fifo[(d->fhead + d->fcount) % 8] = i; d->fcount++; } else LOG("[RED] nn::codec: acquirable queue full at register %u", i); pthread_mutex_unlock(&d->mu); @@ -294,18 +341,24 @@ static void cv_drop_index(uint32_t *q, uint32_t *head, uint32_t *count, uint32_t } static Result cv_dec_unreg(void *t, uint32_t i) { // the buffer leaves the decoder: no longer acquirable, filled or waited for cv_dec *d = cv_of(t); if (!d || i >= CV_BUFS) return CV_R(2004); - pthread_mutex_lock(&d->mu); + dm_host_mutex_lock(&d->mu); d->buf[i].reg = 0; d->buf[i].filled = 0; d->buf[i].pool = NULL; d->buf[i].gen++; cv_drop_index(d->fifo, &d->fhead, &d->fcount, 8, i); cv_drop_index(d->pend, &d->phead, &d->pcount, CV_BUFS, i); pthread_mutex_unlock(&d->mu); return 0; } -static Result cv_dec_reset(void *t) { // Stop / Flush: pictures not yet given to a buffer and a pending end of stream are dropped, the decoder starts over at the next key frame +// Stop / Flush: packets not yet decoded, pictures not yet given to a buffer and a pending end of stream are dropped, and the decoder starts over at the next key frame. The codec +// state is the decoder's thread's: it makes the new one before its next packet (reopen), and drops the pictures of a packet it was decoding (epoch) +static Result cv_dec_reset(void *t) { cv_dec *d = cv_of(t); if (!d) return 0; - pthread_mutex_lock(&d->mu); + dm_host_mutex_lock(&d->mu); + for (uint32_t k = 0; k < d->qcount; k++) free(d->q[(d->qhead + k) % CV_HOLD].data); + d->qhead = d->qcount = 0; for (int i = 0; i < d->nheld; i++) vpx_img_free(d->held[i]); d->nheld = 0; d->eos_pending = 0; - cv_open(d); + d->epoch++; d->reopen = 1; + cv_stat_sum(d); + pthread_cond_signal(&d->work); // it may have waited for room if (d->event) hle_signal_system_event(d->event); pthread_mutex_unlock(&d->mu); return 0; @@ -314,16 +367,12 @@ static Result cv_dec_reset(void *t) { // Stop / Flush: pictures not yet given // then counts only later signals: with none at Start it never sent a packet, and every movie stayed black, with the game waiting behind it static Result cv_dec_start(void *t) { cv_dec *d = cv_of(t); if (!d) return CV_R(2004); - pthread_mutex_lock(&d->mu); - if (d->event && d->nheld < CV_READY) hle_signal_system_event(d->event); + dm_host_mutex_lock(&d->mu); + if (d->event && cv_pending(d) < CV_READY) hle_signal_system_event(d->event); pthread_mutex_unlock(&d->mu); return 0; } static Result cv_dec_event(void **out, void *t) { cv_dec *d = cv_of(t); *out = d ? d->event : NULL; return d ? 0 : CV_R(2004); } -static int cv_hold(cv_dec *d, vpx_image_t *c, int64_t ts) { // a decoded picture waits for a released buffer (decoder lock held); 0 when the host holds no more - if (d->nheld >= CV_HOLD) { static int n; if (n++ < 4) LOG("[RED] nn::codec %s: a packet gave more pictures than the host holds: one dropped", k_cv_name[d->codec]); vpx_img_free(c); return 0; } - d->held[d->nheld] = c; d->held_ts[d->nheld] = ts; d->held_eos[d->nheld] = 0; d->nheld++; return 1; -} static vpx_image_t *nv12_to_i420(const uint8_t *nv12, unsigned w, unsigned h) { // VideoToolbox's NV12 as the I420 the pool keeps vpx_image_t *c = vpx_img_alloc(NULL, VPX_IMG_FMT_I420, w, h, 1); if (!c) return NULL; for (unsigned y = 0; y < h; y++) memcpy(c->planes[0] + (size_t)y * c->stride[0], nv12 + (size_t)y * w, w); @@ -343,39 +392,114 @@ static vpx_image_t *av1_to_i420(const mav1_picture *p) { // the decoder's NV12 } return c; } -// One packet: decoded at once; its pictures wait for released buffers (end of stream marks the last one, or comes as a buffer of its own). -// A refusal (CV_BUSY, nn::codec 3603) is the decoder's defined answer, not a fault: NintendoSDK_movie's detail::SubmitDecoderInputBuffer turns exactly that result into its -// own retry code 0x7a, which VideoDecoder::DecodeAsync hands back to the player, and aborts on any other failure (Ocarina of Time's subsdk0 +0x10fd20, +0x103840). So it is -// logged plainly; a picture the host has to drop prints its own [RED] line (cv_hold) -static Result cv_dec_submit(uint64_t *out, void *t, const void *data, uint64_t size, int64_t ts, bool eos) { - cv_dec *d = cv_of(t); if (!d) return CV_R(2004); - pthread_mutex_lock(&d->mu); - if (d->nheld >= CV_HOLD) { static int n; if (n++ < 4) LOG("nn::codec %s: busy (result 3603), a packet refused with %d pictures waiting for a released buffer",k_cv_name[d->codec], d->nheld); if (d->event) hle_clear_system_event(d->event); pthread_mutex_unlock(&d->mu); return CV_BUSY; } - int got = 0; +// A packet's pictures on their way from the codec to the pictures waiting (held). The packet's last one is kept back until the packet ends, as it carries an end of stream +typedef struct { cv_dec *d; uint32_t epoch; vpx_image_t *last; int64_t last_ts; int stop; uint64_t waited; } cv_out; // stop: a Stop / Flush or Finalize came; waited: time spent waiting for room +// Room for one more waiting picture (decoder lock held, on the decoder's thread): a release makes some (fill). 0 when a Stop / Flush or Finalize came instead +static int cv_room(cv_dec *d, cv_out *o) { + if (d->nheld >= CV_HOLD && !d->quit && o->epoch == d->epoch) { + uint64_t t0 = now_ns(); + while (d->nheld >= CV_HOLD && !d->quit && o->epoch == d->epoch) pthread_cond_wait(&d->work, &d->mu); + o->waited += now_ns() - t0; + } + return !d->quit && o->epoch == d->epoch; +} +static void cv_hold(cv_dec *d, vpx_image_t *c, int64_t ts, int eos) { // decoder lock held, with room + d->held[d->nheld] = c; d->held_ts[d->nheld] = ts; d->held_eos[d->nheld] = (uint8_t)eos; d->nheld++; +} +// A picture of the packet being decoded (the decoder's thread, outside the lock). The one before it, now known not to be the packet's last, joins the waiting pictures; the +// submission-ready event is left to the packet's end, which counts the packet out and its pictures in at once (a client counts its signals) +static void cv_put(cv_out *o, vpx_image_t *c, int64_t ts) { + if (!c) return; + if (o->last) { + cv_dec *d = o->d; + pthread_mutex_lock(&d->mu); + if (cv_room(d, o)) { cv_hold(d, o->last, o->last_ts, 0); fill(d, 1); } else { vpx_img_free(o->last); o->stop = 1; } + pthread_mutex_unlock(&d->mu); + } + o->last = c; o->last_ts = ts; +} +static int cv_idle(cv_dec *d) { pthread_mutex_lock(&d->mu); int idle = !d->qcount; pthread_mutex_unlock(&d->mu); return idle; } // no packet waits behind the one being decoded +// One packet through the codec, on the decoder's thread and outside the decoder's lock (the codec state is that thread's from Initialize to Finalize) +static void cv_decode(cv_dec *d, const uint8_t *data, uint64_t size, int64_t ts, int eos, cv_out *o) { if (d->codec == CV_H264 && d->avc) { // VideoToolbox reorders: pictures leave in presentation order, all of them at the end of the stream if (size && mavc_decode(d->avc, data, (int)size, ts / 1000) < 0) { static int n; if (n++ < 4) LOG("[RED] nn::codec H.264: VideoToolbox could not decode a packet"); } uint8_t *nv12 = malloc((size_t)d->w * d->h * 3 / 2); int64_t pts = 0; - while (nv12 && d->nheld < CV_HOLD && mavc_take(d->avc, eos, nv12, d->w, d->h, &pts) == 1) { vpx_image_t *c = nv12_to_i420(nv12, d->w, d->h); if (c) got += cv_hold(d, c, pts * 1000); } + while (nv12 && !o->stop && mavc_take(d->avc, eos, nv12, d->w, d->h, &pts) == 1) cv_put(o, nv12_to_i420(nv12, d->w, d->h), pts * 1000); free(nv12); } else if (d->codec == CV_AV1) { - if (size) { - mav1_picture pic; - if (mav1_decode(d->av1, data, (size_t)size, &pic) == 1) { vpx_image_t *c = av1_to_i420(&pic); if (c) got += cv_hold(d, c, ts); } - } + // dav1d decodes several frames at once, so a picture comes out some packets after its own went in. With a packet waiting behind this one that is what makes the decoder + // fast, and it goes on to that packet. With none (a client that sends a packet and waits for its picture, or one the decoder is ahead of) the pictures still inside are + // asked for, each waited for, as at the end of the stream; begun, that goes to its end whatever arrives meanwhile (mav1_next) + mav1_picture pic; + int r = size ? mav1_decode(d->av1, data, (size_t)size, ts, &pic) : 0; + while (r == 1 && !o->stop) { cv_put(o, av1_to_i420(&pic), pic.ts); r = mav1_next(d->av1, 0, &pic); } + if (!o->stop && (eos || cv_idle(d))) while (mav1_next(d->av1, 1, &pic) == 1) if (!o->stop) cv_put(o, av1_to_i420(&pic), pic.ts); } else if (size && d->vpx_ok) { if (vpx_codec_decode(&d->vpx, data, (unsigned)size, NULL, 0) != VPX_CODEC_OK) { static int n; if (n++ < 4) LOG("[RED] nn::codec %s: %s (%s)", k_cv_name[d->codec], vpx_codec_error(&d->vpx), vpx_codec_error_detail(&d->vpx) ? vpx_codec_error_detail(&d->vpx) : ""); } vpx_codec_iter_t it = NULL; const vpx_image_t *im; - while ((im = vpx_codec_get_frame(&d->vpx, &it))) { vpx_image_t *c = img_copy(im); if (c) got += cv_hold(d, c, ts); } + while ((im = vpx_codec_get_frame(&d->vpx, &it)) && !o->stop) cv_put(o, img_copy(im), ts); } - if (eos) { if (got) d->held_eos[d->nheld - 1] = 1; else d->eos_pending = 1; } +} +// The decoder's thread: the packets in the order they were taken, one at a time; a packet's pictures wait for released buffers (end of stream marks the last one, or comes as a +// buffer of its own). It starts a packet, and adds a picture to those waiting, only with room for one (a release makes some, fill): no picture is dropped for want of it +void dm_host_helper_qos(qos_class_t q); // hle_thread.c +static void *cv_worker(void *arg) { + cv_dec *d = arg; + pthread_setname_np("dm codec video"); + dm_host_helper_qos(QOS_CLASS_USER_INITIATED); // under DM_QOS_MAP: decodes ahead of playback, not on the frame's critical path (as hle_movie.c's decoder thread) + pthread_mutex_lock(&d->mu); + for (;;) { + while (!d->quit && (!d->qcount || d->nheld >= CV_HOLD)) pthread_cond_wait(&d->work, &d->mu); + if (d->quit) break; + typeof(d->q[0]) p = d->q[d->qhead]; d->qhead = (d->qhead + 1) % CV_HOLD; d->qcount--; + cv_out o = {.d = d, .epoch = d->epoch}; + int reopen = d->reopen; d->reopen = 0; d->busy = 1; + pthread_mutex_unlock(&d->mu); + if (reopen) cv_open(d); + uint64_t t0 = now_ns(); + cv_decode(d, p.data, p.size, p.ts, p.eos, &o); + uint64_t dt = now_ns() - t0 - o.waited; + free(p.data); + pthread_mutex_lock(&d->mu); + if (o.last) cv_room(d, &o); // before the packet is counted out: the client finds the decoder full until then + int before = cv_pending(d); + d->busy = 0; + if (d->quit || o.epoch != d->epoch) { if (o.last) vpx_img_free(o.last); if (d->quit) break; } // Finalize, or a Stop / Flush since the packet was taken: its pictures are dropped + else { + if (o.last) cv_hold(d, o.last, o.last_ts, p.eos); else if (p.eos) d->eos_pending = 1; + fill(d, 1); + } + ready(d, before, 0); + cv_stat(d, dt); + } + pthread_mutex_unlock(&d->mu); + return NULL; +} +// One packet: copied into the decoder's queue for its thread, and the call returns, as the SDK's does. +// A refusal (CV_BUSY, nn::codec 3603) is the decoder's defined answer, not a fault: NintendoSDK_movie's detail::SubmitDecoderInputBuffer turns exactly that result into its +// own retry code 0x7a, which VideoDecoder::DecodeAsync hands back to the player, and aborts on any other failure (Ocarina of Time's subsdk0 +0x10fd20, +0x103840). So it is +// logged plainly +static Result cv_dec_submit(uint64_t *out, void *t, const void *data, uint64_t size, int64_t ts, bool eos) { + cv_dec *d = cv_of(t); if (!d) return CV_R(2004); + dm_host_mutex_lock(&d->mu); + uint8_t *copy = NULL; + if (cv_pending(d) >= CV_HOLD || (size && !(copy = malloc((size_t)size)))) { + static int n; if (n++ < 4) LOG("nn::codec %s: busy (result 3603), a packet refused with %d pictures waiting for a released buffer and %u packets to decode", k_cv_name[d->codec], d->nheld, d->qcount + (uint32_t)d->busy); + if (d->event) hle_clear_system_event(d->event); + pthread_mutex_unlock(&d->mu); return CV_BUSY; + } + if (size) memcpy(copy, data, (size_t)size); + typeof(d->q[0]) *p = &d->q[(d->qhead + d->qcount) % CV_HOLD]; d->qcount++; + p->data = copy; p->size = size; p->ts = ts; p->eos = eos; *out = ++d->submits; - drain(d, 1); + ready(d, 0, 1); + pthread_cond_signal(&d->work); pthread_mutex_unlock(&d->mu); return 0; } static Result cv_dec_acq(uint32_t *idx, cv_sync *sync, void *t) { cv_dec *d = cv_of(t); if (!d) return CV_R(2004); - pthread_mutex_lock(&d->mu); + dm_host_mutex_lock(&d->mu); if (!d->fcount) { pthread_mutex_unlock(&d->mu); return CV_NONE; } uint32_t i = d->fifo[d->fhead]; d->fhead = (d->fhead + 1) % 8; d->fcount--; *idx = i; *sync = (cv_sync){CV_SYNC, d->id, i, d->buf[i].gen}; @@ -384,16 +508,17 @@ static Result cv_dec_acq(uint32_t *idx, cv_sync *sync, void *t) { } static void cv_dec_rel(void *t, uint32_t i, cv_sync sync) { (void)sync; cv_dec *d = cv_of(t); if (!d || i >= CV_BUFS || !d->buf[i].reg) { LOG("[RED] nn::codec::Release…DecoderOutputBuffer index %u", i); return; } - pthread_mutex_lock(&d->mu); + dm_host_mutex_lock(&d->mu); d->buf[i].gen++; d->buf[i].filled = 0; if (d->pcount < CV_BUFS) { d->pend[(d->phead + d->pcount) % CV_BUFS] = i; d->pcount++; } if (d->fcount < 8) { d->fifo[(d->fhead + d->fcount) % 8] = i; d->fcount++; } else LOG("[RED] nn::codec: acquirable queue full at release %u", i); - drain(d, 0); + int before = cv_pending(d); + fill(d, 0); ready(d, before, 0); pthread_mutex_unlock(&d->mu); } static Result cv_dec_props(uint16_t *w, uint16_t *h, uint16_t *cw, uint16_t *ch, int64_t *ts, bool *eos, void *t, uint32_t i) { cv_dec *d = cv_of(t); if (!d || i >= CV_BUFS) return CV_R(2004); - pthread_mutex_lock(&d->mu); + dm_host_mutex_lock(&d->mu); int ok = d->buf[i].filled; if (ok) { *w = *cw = d->buf[i].w; *h = *ch = d->buf[i].h; *ts = d->buf[i].ts; *eos = d->buf[i].eos != 0; } pthread_mutex_unlock(&d->mu); @@ -408,11 +533,11 @@ static Result cv_dec_encrypted(void) { static int once; if (!once++) LOG("[RED] HLE_FORCE(s_fin, "frees the host decoder", Result, h_cv_##tag##fin, void *t) { return cv_dec_fin(t); } \ HLE_FORCE(s_reg, "a buffer of the host decoder, acquirable at once", Result, h_cv_##tag##reg, void *t, uint32_t i, void *pool, uint32_t pidx) { return cv_dec_reg(t, i, pool, pidx); } \ HLE_FORCE(s_unreg, "the buffer leaves the host decoder", Result, h_cv_##tag##unreg, void *t, uint32_t i) { return cv_dec_unreg(t, i); } \ - HLE_FORCE(s_start, "the host decoder decodes on submission; ready for packets from here on", Result, h_cv_##tag##start, void *t) { return cv_dec_start(t); } \ - HLE_FORCE(s_stop, "drops undelivered pictures", Result, h_cv_##tag##stop, void *t) { return cv_dec_reset(t); } \ - HLE_FORCE(s_flush, "drops undelivered pictures", Result, h_cv_##tag##flush, void *t) { return cv_dec_reset(t); } \ + HLE_FORCE(s_start, "the host decoder takes packets from here on", Result, h_cv_##tag##start, void *t) { return cv_dec_start(t); } \ + HLE_FORCE(s_stop, "drops undecoded packets and undelivered pictures", Result, h_cv_##tag##stop, void *t) { return cv_dec_reset(t); } \ + HLE_FORCE(s_flush, "drops undecoded packets and undelivered pictures", Result, h_cv_##tag##flush, void *t) { return cv_dec_reset(t); } \ HLE_FORCE(s_ev, "signalled while the host decoder takes packets", Result, h_cv_##tag##event, void **out, void *t) { return cv_dec_event(out, t); } \ - HLE_FORCE(s_sub, "decodes the packet on the submitting thread", Result, h_cv_##tag##submit, uint64_t *out, void *t, const void *data, uint64_t size, int64_t ts, bool eos) { return cv_dec_submit(out, t, data, size, ts, eos); } \ + HLE_FORCE(s_sub, "queues the packet for the host decoder's thread", Result, h_cv_##tag##submit, uint64_t *out, void *t, const void *data, uint64_t size, int64_t ts, bool eos) { return cv_dec_submit(out, t, data, size, ts, eos); } \ HLE_FORCE(s_enc, "protected streams are not served", Result, h_cv_##tag##enc, void) { return cv_dec_encrypted(); } \ HLE_FORCE(s_acq, "the oldest acquirable buffer and its sync handle", Result, h_cv_##tag##acq, uint32_t *idx, cv_sync *sync, void *t) { return cv_dec_acq(idx, sync, t); } \ HLE_FORCE(s_rel, "the buffer waits for the next picture and is acquirable again", void, h_cv_##tag##rel, void *t, uint32_t i, cv_sync sync) { cv_dec_rel(t, i, sync); } \ @@ -521,10 +646,10 @@ HLE_FORCE("_ZN2nn5codec3sdk34MakeDecodeImagePreferenceForCompatEttNS0_24VideoDec static bool sync_reached(const cv_sync *s) { if (s->magic != CV_SYNC) { static int once; if (!once++ && (s->magic || s->dec)) LOG("[RED] nn::codec: a sync handle the host did not make (%#x): signalled", s->magic); return true; } if (!s->gen) return true; - pthread_mutex_lock(&g_cv_mu); // held until the decoder's lock is: FinalizeVp9Decoder cannot free it in between + dm_host_mutex_lock(&g_cv_mu); // held until the decoder's lock is: FinalizeVp9Decoder cannot free it in between cv_dec *d = s->dec && s->dec <= 16 ? g_cv[s->dec - 1] : NULL; bool r = true; - if (d && s->idx < CV_BUFS) { pthread_mutex_lock(&d->mu); r = d->buf[s->idx].filled && d->buf[s->idx].filled_gen >= s->gen; pthread_mutex_unlock(&d->mu); } + if (d && s->idx < CV_BUFS) { dm_host_mutex_lock(&d->mu); r = d->buf[s->idx].filled && d->buf[s->idx].filled_gen >= s->gen; pthread_mutex_unlock(&d->mu); } pthread_mutex_unlock(&g_cv_mu); return r; } diff --git a/dm/host/hle_movie_av1.c b/dm/host/hle_movie_av1.c index d659b45e19..8551fc3ba1 100644 --- a/dm/host/hle_movie_av1.c +++ b/dm/host/hle_movie_av1.c @@ -3,7 +3,8 @@ // aborts on a decoder that does not initialize (movie::detail::InitializeDecoderByTransferMemory, subsdk2+0xf9b4), so without one a game with AV1 movies could not run there. // VideoToolbox wants a format description holding the stream's av1C record (ISO-BMFF AV1 binding, 2.3.3): four bytes read from the sequence header, then that header's OBU. The decoder API takes no // configuration for AV1, so the sequence header comes from the stream, where every key frame carries one (AV1 5.5); a changed one makes a new session. A temporal unit goes in whole, its OBUs in -// the low-overhead format WebM and the SDK's demuxer keep them in (each with its size). Decoding is synchronous and a temporal unit shows at most one frame, in presentation order, so no queue +// the low-overhead format WebM and the SDK's demuxer keep them in (each with its size). Decoding is synchronous and a temporal unit shows at most one frame, in presentation order, so no queue. +// dav1d decodes several frames at once (frame threads), so its pictures come out later than their units go in, each with its unit's time (mav1_next) #include "hle.h" #include #include "dav1d/dav1d.h" @@ -15,6 +16,8 @@ struct mav1 { CVPixelBufferRef got, locked; int soft; // dav1d decodes: no hardware decoder, DM_AV1_DAV1D=1, or a stream VideoToolbox refused (until mav1_reset) Dav1dContext *dav1d; Dav1dPicture pic; int has_pic; + Dav1dData in; // the temporal unit dav1d has not taken whole yet + int draining; // a drain gave a picture and has not reached its end (dav1d_step) uint8_t *y8, *uv; size_t ny8, nuv; // dav1d's picture as NV12: the chroma interleaved, and the luma of a 10- or 12-bit stream shifted to 8 bits int red; }; @@ -30,7 +33,7 @@ static void av1_close(mav1 *a) { if (a->fd) { CFRelease(a->fd); a->fd = NULL; } if (a->got) { CVPixelBufferRelease(a->got); a->got = NULL; } } -void mav1_reset(mav1 *a) { unlock_picture(a); av1_close(a); a->nseq = 0; if (a->dav1d) dav1d_flush(a->dav1d); a->soft = !hw_av1(); } +void mav1_reset(mav1 *a) { unlock_picture(a); av1_close(a); a->nseq = 0; if (a->in.sz) dav1d_data_unref(&a->in); if (a->dav1d) dav1d_flush(a->dav1d); a->draining = 0; a->soft = !hw_av1(); } void mav1_free(mav1 *a) { if (a) { mav1_reset(a); if (a->dav1d) dav1d_close(&a->dav1d); free(a->y8); free(a->uv); free(a); } } // ---- The sequence header (AV1 5.5), read as far as the colour config ---- @@ -173,39 +176,76 @@ static int dav1d_nv12(mav1 *a, const Dav1dPicture *p, mav1_picture *out) { } unsigned mc = p->seq_hdr->mtrx; // matrix coefficients (AV1 6.4.2); unspecified, BT.601 below 720 lines and BT.709 from there, as VideoToolbox attaches to such a stream's pictures if (mc == DAV1D_MC_UNKNOWN) mc = h < 720 ? DAV1D_MC_BT601 : DAV1D_MC_BT709; - *out = (mav1_picture){y, a->uv, ys, (size_t)cw * 2, w, h, mc == DAV1D_MC_BT709 ? 2 : mc == DAV1D_MC_BT2020_NCL || mc == DAV1D_MC_BT2020_CL ? 5 : 1, p->seq_hdr->color_range}; + *out = (mav1_picture){y, a->uv, ys, (size_t)cw * 2, w, h, mc == DAV1D_MC_BT709 ? 2 : mc == DAV1D_MC_BT2020_NCL || mc == DAV1D_MC_BT2020_CL ? 5 : 1, p->seq_hdr->color_range, p->m.timestamp}; return 1; } -static int decode_dav1d(mav1 *a, const uint8_t *data, size_t n, mav1_picture *out) { - if (!a->dav1d) { - Dav1dSettings st; dav1d_default_settings(&st); - st.n_threads = 2; st.max_frame_delay = 1; // a temporal unit's picture before its send returns: one frame at a time, two task threads decoding it while the submitting thread waits - st.logger.cookie = a; st.logger.callback = d_log; - if (dav1d_open(&a->dav1d, &st)) { a->dav1d = NULL; if (!a->red++) LOG("[RED] movie: dav1d could not be opened"); return -1; } - static int once; if (!once++) LOG("[movie] AV1: dav1d %s decoding (%s)", dav1d_version(), hw_av1() ? "a stream VideoToolbox refused" : getenv("DM_AV1_DAV1D") ? "DM_AV1_DAV1D" : "no hardware AV1 decoder"); +// dav1d's threads. A temporal unit of a hierarchical stream holds several frames (the hidden ones the next units only show), and decoded one after the other they made that +// unit many times longer than the others: Ocarina of Time's 1080p 60 fps title movie took 80 to 122 ms for one unit in 32 on an M2 Pro (two task threads, one frame at a time) +// and 15.4 ms a unit over its heaviest five seconds, at a budget of 16.7. Frame threads decode those frames, and the units waiting behind them, side by side +#define DAV1D_THREADS 4 +#define DAV1D_FRAMES 3 +static int dav1d_open_once(mav1 *a) { + if (a->dav1d) return 1; + Dav1dSettings st; dav1d_default_settings(&st); + st.n_threads = DAV1D_THREADS; st.max_frame_delay = DAV1D_FRAMES; + st.logger.cookie = a; st.logger.callback = d_log; + if (dav1d_open(&a->dav1d, &st)) { a->dav1d = NULL; if (!a->red++) LOG("[RED] movie: dav1d could not be opened"); return 0; } + static int once; if (!once++) LOG("[movie] AV1: dav1d %s decoding, %d threads on %d frames at once (%s)", dav1d_version(), st.n_threads, st.max_frame_delay, + hw_av1() ? "a stream VideoToolbox refused" : getenv("DM_AV1_DAV1D") ? "DM_AV1_DAV1D" : "no hardware AV1 decoder"); + return 1; +} +// Gives dav1d what it has not taken of the unit, then asks it for one picture: 1 with it, 0 none now, -1 the unit was refused. One dav1d_get_picture for each dav1d_send_data: +// a second one in a row is dav1d's drain, which waits for the frames in flight and so decodes them one after the other. With drain, and the unit taken, that is what is asked. +// A drain that has given a picture must go on to its end (EAGAIN) before the next unit: dav1d (1.5.4, lib.c drain_picture) steps over its empty frame contexts on the way to +// the oldest frame, which leaves frame_thread.next on a frame still in flight if data comes then. The next frame waits for that one and retires it with task_thread.first one +// context past the oldest frame for good, and retiring a frame cancels the task rescan asked for task_thread.first: a live frame's from then on. Its task is never run, the +// workers sleep and dav1d_submit_frame waits for ever (found when the drain stopped as soon as a packet arrived: Ocarina of Time's title movie froze in 3 runs of 6) +static int dav1d_step(mav1 *a, int drain, mav1_picture *out) { + for (int tries = 0; tries < 64; tries++) { + int draining = !a->in.sz; // nothing to give: this get is the second in a row + if (a->in.sz) { + int r = dav1d_send_data(a->dav1d, &a->in); // EAGAIN: a picture has to be taken first + if (r && r != DAV1D_ERR(EAGAIN)) { dav1d_data_unref(&a->in); if (!a->red++) LOG("[RED] movie: dav1d refused a temporal unit (%d, first case)", r); return -1; } + } else if (!drain) return 0; + Dav1dPicture p = {0}; + int g = dav1d_get_picture(a->dav1d, &p); + if (!g) { + if (draining) a->draining = 1; + if (a->has_pic) dav1d_picture_unref(&a->pic); + a->pic = p; a->has_pic = 1; + if (!dav1d_nv12(a, &a->pic, out)) { if (!a->red++) LOG("[RED] movie: no memory for a %dx%d AV1 picture", a->pic.p.w, a->pic.p.h); return -1; } + return 1; + } + if (g == DAV1D_ERR(EAGAIN)) { if (draining) a->draining = 0; } + else if (!a->red++) LOG("[RED] movie: dav1d could not decode a frame (%d, first case)", g); + if (!a->in.sz && (g == DAV1D_ERR(EAGAIN) || !drain)) return 0; // the unit is in and no picture is ready; a frame in error is passed over while draining } - Dav1dData d = {0}; uint8_t *buf = dav1d_data_create(&d, n); - if (!buf) return -1; - memcpy(buf, data, n); - Dav1dPicture p = {0}; int got = 0; - for (int tries = 0; d.sz && tries < 64; tries++) { - int r = dav1d_send_data(a->dav1d, &d); - if (r && r != DAV1D_ERR(EAGAIN)) { dav1d_data_unref(&d); if (!a->red++) LOG("[RED] movie: dav1d refused a temporal unit (%d, first case)", r); return -1; } - while (!dav1d_get_picture(a->dav1d, &p)) { if (a->has_pic) dav1d_picture_unref(&a->pic); a->pic = p; a->has_pic = 1; got = 1; } // one shown picture a temporal unit; a later one replaces it + if (a->in.sz) { dav1d_data_unref(&a->in); if (!a->red++) LOG("[RED] movie: dav1d took no more data, a temporal unit dropped (first case)"); return -1; } + return 0; +} +static int decode_dav1d(mav1 *a, const uint8_t *data, size_t n, int64_t ts, mav1_picture *out) { + if (!dav1d_open_once(a)) return -1; + if (a->in.sz) dav1d_data_unref(&a->in); // a unit left unfinished (its caller stopped): dropped + if (a->draining) { // a drain its caller left: ended here, its pictures lost + int lost = 0; + for (int tries = 0; tries < 64; tries++) { Dav1dPicture p = {0}; int g = dav1d_get_picture(a->dav1d, &p); if (!g) { dav1d_picture_unref(&p); lost++; } else if (g == DAV1D_ERR(EAGAIN)) break; } + a->draining = 0; + LOG("[RED] movie: an AV1 drain was left before its end: %d picture(s) dropped", lost); } - if (d.sz) { dav1d_data_unref(&d); if (!a->red++) LOG("[RED] movie: dav1d took no more data, a temporal unit dropped (first case)"); return -1; } - if (!got) return 0; - if (!dav1d_nv12(a, &a->pic, out)) { if (!a->red++) LOG("[RED] movie: no memory for a %dx%d AV1 picture", a->pic.p.w, a->pic.p.h); return -1; } - return 1; + uint8_t *buf = dav1d_data_create(&a->in, n); + if (!buf) return -1; + memcpy(buf, data, n); a->in.m.timestamp = ts; + return dav1d_step(a, 0, out); } +int mav1_next(mav1 *a, int drain, mav1_picture *out) { return a->soft && a->dav1d ? dav1d_step(a, drain, out) : 0; } -int mav1_decode(mav1 *a, const uint8_t *data, size_t n, mav1_picture *out) { +int mav1_decode(mav1 *a, const uint8_t *data, size_t n, int64_t ts, mav1_picture *out) { + if (a->soft) return decode_dav1d(a, data, n, ts, out); unlock_picture(a); - if (a->soft) return decode_dav1d(a, data, n, out); size_t seqn = 0; const uint8_t *seq = find_seq(data, n, &seqn); if (seq && (seqn != a->nseq || memcmp(seq, a->seq, seqn) || !a->vs) && !av1_open(a, seq, seqn)) { // a stream VideoToolbox does not take: dav1d from this temporal unit on (it holds the sequence header) LOG("[movie] AV1: dav1d decodes the stream instead"); av1_close(a); a->soft = 1; - return decode_dav1d(a, data, n, out); + return decode_dav1d(a, data, n, ts, out); } if (!a->vs) return 0; // the stream's first sequence header has not come CMBlockBufferRef bb = NULL; CMSampleBufferRef sb = NULL; size_t ssz = n; @@ -222,7 +262,7 @@ int mav1_decode(mav1 *a, const uint8_t *data, size_t n, mav1_picture *out) { CFStringRef m = CVBufferCopyAttachment(pb, kCVImageBufferYCbCrMatrixKey, NULL); *out = (mav1_picture){CVPixelBufferGetBaseAddressOfPlane(pb, 0), CVPixelBufferGetBaseAddressOfPlane(pb, 1), CVPixelBufferGetBytesPerRowOfPlane(pb, 0), CVPixelBufferGetBytesPerRowOfPlane(pb, 1), (int)CVPixelBufferGetWidthOfPlane(pb, 0), (int)CVPixelBufferGetHeightOfPlane(pb, 0), - !m || CFEqual(m, kCVImageBufferYCbCrMatrix_ITU_R_709_2) ? 2 : CFEqual(m, kCVImageBufferYCbCrMatrix_ITU_R_2020) ? 5 : 1, 0}; + !m || CFEqual(m, kCVImageBufferYCbCrMatrix_ITU_R_709_2) ? 2 : CFEqual(m, kCVImageBufferYCbCrMatrix_ITU_R_2020) ? 5 : 1, 0, ts}; if (m) CFRelease(m); return 1; } diff --git a/dm/host/hle_movie_av1.h b/dm/host/hle_movie_av1.h index 84594e8ba6..d951a4df7a 100644 --- a/dm/host/hle_movie_av1.h +++ b/dm/host/hle_movie_av1.h @@ -4,14 +4,20 @@ #include typedef struct mav1 mav1; -// What one decode gave: an NV12 picture of w x h in the decoder's memory, valid until the next call, its matrix as vpx_color_space_t's values (BT.601 = 1, BT.709 = 2, BT.2020 = 5) -typedef struct { const uint8_t *y, *uv; size_t ystride, uvstride; int w, h, matrix, full_range; } mav1_picture; +// What one decode gave: an NV12 picture of w x h in the decoder's memory, valid until the next call, its matrix as vpx_color_space_t's values (BT.601 = 1, BT.709 = 2, BT.2020 = 5), +// and the time its temporal unit came with: dav1d decodes several frames at once, so a picture can come out calls after its unit went in +typedef struct { const uint8_t *y, *uv; size_t ystride, uvstride; int w, h, matrix, full_range; int64_t ts; } mav1_picture; mav1 *mav1_new(void); void mav1_free(mav1 *a); void mav1_reset(mav1 *a); // a new stream starts at the next packet with a sequence header -// One temporal unit (OBUs with their sizes). 1 and *out set: a picture; 0: nothing to show (no sequence header seen yet, a unit without a shown frame); -1: the decoder refused it -int mav1_decode(mav1 *a, const uint8_t *data, size_t n, mav1_picture *out); +// One temporal unit (OBUs with their sizes) and its time. 1 and *out set: a picture, the oldest not yet given; 0: nothing to show now (no sequence header seen yet, a unit +// without a shown frame, or dav1d still decodes it); -1: the decoder refused it +int mav1_decode(mav1 *a, const uint8_t *data, size_t n, int64_t ts, mav1_picture *out); +// More pictures after mav1_decode, one a call until it returns 0. drain 0: those the unit's last part gives (dav1d gave a picture before it had taken the whole unit). +// drain 1: also the pictures of the frames dav1d still decodes, waiting for each: at the end of the stream, or when no unit follows this one for now. Once such a call has +// given a picture, the calls go on until one returns 0 before the next mav1_decode (dav1d's drain cannot be left halfway: dav1d_step) +int mav1_next(mav1 *a, int drain, mav1_picture *out); const char *mav1_backend(const mav1 *a); // "VideoToolbox" (its hardware decoder: Apple M3 and A17 Pro on) or "dav1d" // Exposed for its test: fills the 4 + n bytes of an av1C record from a sequence header OBU (with its header and size); 0 when the OBU cannot be read int mav1_av1c(const uint8_t *obu, size_t n, uint8_t c[4], int *w, int *h); diff --git a/dm/host/tests/t_codec_video.c b/dm/host/tests/t_codec_video.c index c73dd0f7b1..2849cec904 100644 --- a/dm/host/tests/t_codec_video.c +++ b/dm/host/tests/t_codec_video.c @@ -1,6 +1,8 @@ // The Switch 2's video decoder API as the host serves it (hle_codec_video.c), without a guest: the buffer protocol, results, sync handles, sync point events and the // readback, on synthetic red key frames: 16x16 VP9 and VP8 (the ones t_movie_vpx.c decodes), a 64x64 H.264 baseline frame (ffmpeg's libx264, SEI removed) and a 64x64 AV1 frame -// (SVT-AV1 through PyAV, preset 12, CRF 30); no game data. The SystemEvent functions are stubs that record each event's state. +// (SVT-AV1 through PyAV, preset 12, CRF 30); no game data. The SystemEvent functions are stubs that record each event's state and the thread that signalled it last. +// A submission returns with its packet queued for the decoder's thread: settle() waits for that thread before a check reads what the packet leads to; the checks made +// without it hold however far the thread has got. #include "../hle.h" #undef HLE_FORCE #define HLE_FORCE(mangled, why, ret, cname, ...) static ret cname(__VA_ARGS__) @@ -9,16 +11,25 @@ #include "../hle_movie_avc.c" #include "../hle_movie_av1.c" #include +#include uint64_t now_ns(void) { return 1; } __thread _Atomic int dm_host_work; // hle_thread.c -static struct { void *ev; int bound, set; } g_ev[16]; -static int ev_slot(void *e) { for (int i = 0; i < 16; i++) if (g_ev[i].ev == e) return i; for (int i = 0; i < 16; i++) if (!g_ev[i].ev) { g_ev[i].ev = e; return i; } abort(); } -void hle_bind_system_event(void *e, int autoclear) { (void)autoclear; g_ev[ev_slot(e)].bound = 1; } -void hle_signal_system_event(void *e) { g_ev[ev_slot(e)].set = 1; } -void hle_clear_system_event(void *e) { g_ev[ev_slot(e)].set = 0; } -static int ev_set(void *e) { return g_ev[ev_slot(e)].set; } -static void destroy_ev(void *e) { g_ev[ev_slot(e)].bound = g_ev[ev_slot(e)].set = 0; } // nn::os::DestroySystemEvent: closing the handle unbinds the event +void dm_host_helper_qos(qos_class_t q) { (void)q; } // hle_thread.c: the decoder's thread keeps the default class in the unit test +static struct { void *ev; int bound, set; pthread_t by; } g_ev[16]; // by: the thread that signalled it last +static pthread_mutex_t g_ev_mu = PTHREAD_MUTEX_INITIALIZER; // the decoder's thread signals and clears events too +static int ev_slot_locked(void *e) { for (int i = 0; i < 16; i++) if (g_ev[i].ev == e) return i; for (int i = 0; i < 16; i++) if (!g_ev[i].ev) { g_ev[i].ev = e; return i; } abort(); } +static int ev_slot(void *e) { pthread_mutex_lock(&g_ev_mu); int i = ev_slot_locked(e); pthread_mutex_unlock(&g_ev_mu); return i; } +void hle_bind_system_event(void *e, int autoclear) { (void)autoclear; pthread_mutex_lock(&g_ev_mu); g_ev[ev_slot_locked(e)].bound = 1; pthread_mutex_unlock(&g_ev_mu); } +void hle_signal_system_event(void *e) { pthread_mutex_lock(&g_ev_mu); int i = ev_slot_locked(e); g_ev[i].set = 1; g_ev[i].by = pthread_self(); pthread_mutex_unlock(&g_ev_mu); } +void hle_clear_system_event(void *e) { pthread_mutex_lock(&g_ev_mu); g_ev[ev_slot_locked(e)].set = 0; pthread_mutex_unlock(&g_ev_mu); } +static int ev_set(void *e) { pthread_mutex_lock(&g_ev_mu); int r = g_ev[ev_slot_locked(e)].set; pthread_mutex_unlock(&g_ev_mu); return r; } +static int ev_by_me(void *e) { pthread_mutex_lock(&g_ev_mu); int r = pthread_equal(g_ev[ev_slot_locked(e)].by, pthread_self()); pthread_mutex_unlock(&g_ev_mu); return r; } +static void destroy_ev(void *e) { pthread_mutex_lock(&g_ev_mu); int i = ev_slot_locked(e); g_ev[i].bound = g_ev[i].set = 0; pthread_mutex_unlock(&g_ev_mu); } // nn::os::DestroySystemEvent: closing the handle unbinds the event +static void settle(void *t) { // the decoder's thread has decoded every packet it can (all of them, or it waits for room for another picture) + cv_dec *d = cv_of(t); + for (;;) { pthread_mutex_lock(&d->mu); int idle = !d->busy && (!d->qcount || d->nheld >= CV_HOLD); pthread_mutex_unlock(&d->mu); if (idle) return; usleep(200); } +} void *guest_sym(const char *n) { return !strcmp(n, "_ZN2nn2os18DestroySystemEventEPNS0_15SystemEventTypeE") ? (void *)destroy_ev : NULL; } static vpx_image_t *black_i420(unsigned w, unsigned h) { vpx_image_t *c = vpx_img_alloc(NULL, VPX_IMG_FMT_I420, w, h, 1); if (!c) return NULL; @@ -73,7 +84,7 @@ int main(void) { assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 0 && sync.gen == 1 && !h_gs_trywait(&sync)); assert(h_cv_vp9props(&w, &h, &cw, &ch, &ts, &eos, dec, 0) == CV_NONE); assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 1000, false) && id == 1); - assert(h_gs_trywait(&sync)); + settle(dec); assert(h_gs_trywait(&sync)); assert(!h_cv_vp9props(&w, &h, &cw, &ch, &ts, &eos, dec, 0) && w == 16 && h == 16 && cw == 16 && ch == 16 && ts == 1000 && !eos); uint32_t cs = 7; w = h = 0; // SDK 19's form: the same properties, and colour space 0 assert(!h_cv_vp9props19(&w, &h, &cw, &ch, &cs, &ts, &eos, dec, 0) && w == 16 && h == 16 && ts == 1000 && !eos && cs == 0); @@ -86,11 +97,14 @@ int main(void) { assert(!h_cv_rgba(pool[0], 0, 0, 0, 16, 16, rgba, 64, sizeof rgba)); for (int i = 0; i < 1024; i += 4) assert(rgba[i] >= 250 && rgba[i + 1] <= 5 && rgba[i + 2] <= 5 && rgba[i + 3] == 255); - // No released buffer: pictures wait; the event goes down at CV_READY, with room left for a client's signal in flight, and packets are refused (3603) at CV_HOLD + // No released buffer: pictures wait; the event goes down at CV_READY, with room left for a client's signal in flight, and packets are refused (3603) at CV_HOLD. + // A packet not yet decoded counts as the picture it will give: the event and the refusal are the same whether the decoder's thread has got to it or not for (int i = 0; i < CV_READY; i++) assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 2000 + i, false)); - assert(d->nheld == CV_READY && !ev_set(ev)); + assert(!ev_set(ev)); + settle(dec); assert(d->nheld == CV_READY && !d->qcount && !ev_set(ev)); for (int i = CV_READY; i < CV_HOLD; i++) assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 2000 + i, false)); - assert(d->nheld == CV_HOLD && !ev_set(ev)); + assert(h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 9999, false) == CV_BUSY && !ev_set(ev)); + settle(dec); assert(d->nheld == CV_HOLD && !d->qcount && !ev_set(ev)); assert(h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 9999, false) == CV_BUSY); // A release takes the oldest; the event comes back below CV_READY for (int i = CV_HOLD; i > CV_READY; i--) { h_cv_vp9rel(dec, 1, sync); assert(d->nheld == i - 1 && !ev_set(ev)); assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 1); } @@ -104,7 +118,8 @@ int main(void) { hle_clear_system_event(ev); h_cv_vp9rel(dec, 1, sync); assert(d->nheld == CV_READY - 2 && !ev_set(ev)); assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 1); - assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 2000 + CV_HOLD, false) && d->nheld == CV_READY - 1 && ev_set(ev)); + assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 2000 + CV_HOLD, false) && ev_set(ev) && ev_by_me(ev)); // signalled by the submission itself, before the packet is decoded + settle(dec); assert(d->nheld == CV_READY - 1 && ev_set(ev)); assert(!h_cv_vp9props(&w, &h, &cw, &ch, &ts, &eos, dec, 1) && ts == 2000 + CV_HOLD - CV_READY + 1); // Sync point event: armed on an unfilled buffer, signalled when the picture lands; one armed on a filled buffer is signalled at once @@ -116,24 +131,40 @@ int main(void) { for (int i = 0; i < 2; i++) { h_cv_vp9rel(dec, (uint32_t)i, sync); assert(!h_cv_vp9acq(&idx, &sync, dec)); } // the last two waiting pictures go out h_cv_vp9rel(dec, 2, sync); assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 2 && !h_gs_trywait(&sync)); assert(!h_spt_request(spt, &sync) && !ev_set(spt) && SPT(spt)->armed); - assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 3000, false) && ev_set(spt) && !SPT(spt)->armed && h_gs_trywait(&sync)); + assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 3000, false)); + settle(dec); assert(ev_set(spt) && !SPT(spt)->armed && h_gs_trywait(&sync)); + assert(!ev_by_me(spt)); // the picture came from the decoder's thread, not from inside the submission // End of stream with no data: the next released buffer carries it, with no picture - assert(!h_cv_vp9submit(&id, dec, NULL, 0, 0, true) && d->eos_pending); + assert(!h_cv_vp9submit(&id, dec, NULL, 0, 0, true)); + settle(dec); assert(d->eos_pending); h_cv_vp9rel(dec, 2, sync); assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 2 && h_gs_trywait(&sync)); assert(!h_cv_vp9props(&w, &h, &cw, &ch, &ts, &eos, dec, 2) && eos && w == 0 && h == 0); // A pool finalized while its buffer is still registered: the buffer keeps working, its picture has nowhere to go (ASan checks no freed pool is written) h_cv_poolfin(pool[1]); assert(!pool_of(pool[1]) && d->buf[1].pool == NULL); h_cv_vp9rel(dec, 1, sync); assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 1 && !h_gs_trywait(&sync)); - assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 4000, false) && h_gs_trywait(&sync)); + assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 4000, false)); + settle(dec); assert(h_gs_trywait(&sync)); assert(!h_cv_vp9props(&w, &h, &cw, &ch, &ts, &eos, dec, 1) && ts == 4000 && w == 16); - // A flush drops the waiting pictures and restarts the decoder; finalize frees it and destroys its event - assert(!h_cv_vp9flush(dec) && d->nheld == 0 && d->vpx_ok && ev_set(ev)); + // A flush drops the waiting pictures and the packets not yet decoded, wherever the decoder's thread is with them, and restarts the decoder: none of them reaches a buffer + // released afterwards, the next key frame does; finalize frees the decoder and destroys its event + for (int round = 0; round < 8; round++) { + for (int i = 0; i < 6; i++) assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 5000 + i, false)); + if (round & 1) usleep(100u * (unsigned)round); // some rounds catch the thread inside a packet, some before or after + assert(!h_cv_vp9flush(dec) && d->nheld == 0 && !d->qcount && ev_set(ev)); + settle(dec); assert(d->nheld == 0 && !d->eos_pending); + h_cv_vp9rel(dec, 1, sync); assert(!h_cv_vp9acq(&idx, &sync, dec) && idx == 1 && !h_gs_trywait(&sync)); + assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 6000 + round, false)); + settle(dec); assert(d->vpx_ok && !d->reopen && h_gs_trywait(&sync)); + assert(!h_cv_vp9props(&w, &h, &cw, &ch, &ts, &eos, dec, 1) && ts == 6000 + round && w == 16 && d->nheld == 0); + } assert(!h_cv_vp9fin(dec) && !cv_of(dec) && !g_ev[ev_slot(ev)].bound); - // A decoder initialised again in the same memory, cleared in between (Donkey Kong Bananza's second movie): its event is bound anew + // A decoder initialised again in the same memory, cleared in between (Donkey Kong Bananza's second movie): its event is bound anew. + // Finalized with packets it has not decoded: its thread ends first, and they go with it memset(dec, 0, sizeof dec); assert(!h_cv_vp9init2(dec, 0x10000, 16, 16, 1, 1, 3) && cv_of(dec) && g_ev[ev_slot(ev)].bound && ev_set(ev)); + for (int i = 0; i < 6; i++) assert(!h_cv_vp9submit(&id, dec, vp9, sizeof vp9, 7000 + i, false)); assert(!h_cv_vp9fin(dec) && !cv_of(dec) && !g_ev[ev_slot(ev)].bound); for (int i = 0; i < 3; i += 2) { h_cv_poolfin(pool[i]); assert(!pool_of(pool[i])); } // VP8 (libvpx) and H.264 (VideoToolbox) take the same protocol: one released buffer, one key frame, its picture read back red @@ -142,7 +173,8 @@ int main(void) { assert(!h_cv_vp8init2(d8, 0x10000, 16, 16, 1, 1, 3) && cv_of(d8) && cv_of(d8)->codec == CV_VP8 && cv_of(d8)->vpx_ok); assert(!h_cv_vp8reg(d8, 0, p8, 0) && !h_cv_vp8acq(&idx, &sync, d8) && idx == 0); h_cv_vp8rel(d8, 0, sync); assert(!h_cv_vp8acq(&idx, &sync, d8) && !h_gs_trywait(&sync)); - assert(!h_cv_vp8submit(&id, d8, vp8, sizeof vp8, 7000, false) && h_gs_trywait(&sync)); + assert(!h_cv_vp8submit(&id, d8, vp8, sizeof vp8, 7000, false)); + settle(d8); assert(h_gs_trywait(&sync)); assert(!h_cv_vp8props(&w, &h, &cw, &ch, &ts, &eos, d8, 0) && w == 16 && h == 16 && ts == 7000); assert(!h_cv_nv12(p8, 0, 0, 0, 16, 16, nv12, 16, 256, nv12 + 256, 16, 128)); for (int i = 0; i < 256; i++) assert(abs(nv12[i] - 81) <= 3); @@ -157,7 +189,8 @@ int main(void) { assert(!h_cv_h264init2(dh, 0x10000, 64, 64, 1, 1, 3) && cv_of(dh) && cv_of(dh)->codec == CV_H264 && cv_of(dh)->avc); assert(!h_cv_h264reg(dh, 0, ph, 0) && !h_cv_h264acq(&idx, &sync, dh)); h_cv_h264rel(dh, 0, sync); assert(!h_cv_h264acq(&idx, &sync, dh) && !h_gs_trywait(&sync)); - assert(!h_cv_h264submit(&id, dh, h264, sizeof h264, 5000000, true) && h_gs_trywait(&sync)); // end of stream: VideoToolbox gives its picture out + assert(!h_cv_h264submit(&id, dh, h264, sizeof h264, 5000000, true)); // end of stream: VideoToolbox gives its picture out + settle(dh); assert(h_gs_trywait(&sync)); assert(!h_cv_h264props(&w, &h, &cw, &ch, &ts, &eos, dh, 0) && w == 64 && h == 64 && ts == 5000000 && eos); assert(!h_cv_nv12(ph, 0, 0, 0, 64, 64, yuv, 64, 4096, yuv + 4096, 64, 2048)); for (int i = 0; i < 4096; i++) assert(abs(yuv[i] - 81) <= 4); @@ -169,7 +202,13 @@ int main(void) { assert(!h_cv_av1tm(da, NULL, 0, 0x10000, 0xabcd0080, 0xabcd0040, 1, 3, 2, 2) && cv_of(da) && cv_of(da)->codec == CV_AV1 && cv_of(da)->w == 0x80 && cv_of(da)->h == 0x40); assert(h_cv_av1ev22(da) == da + CV_EVENT_OFF && ev_set(da + CV_EVENT_OFF)); static const uint8_t delimiter[] = {0x12, 0x00}; // a temporal delimiter OBU alone - uint64_t n; assert(!h_cv_av1submit(&n, da, delimiter, sizeof delimiter, 0, false) && !cv_of(da)->nheld); + uint64_t n; assert(!h_cv_av1submit(&n, da, delimiter, sizeof delimiter, 0, false)); + settle(da); assert(!cv_of(da)->nheld); + // Key frames sent without waiting for their pictures, the last with the end of stream: every picture waits with its own packet's time, in order, and the last one + // carries the end of stream, whichever backend decodes and however many frames it holds at once + for (int k = 0; k < 7; k++) assert(!h_cv_av1submit(&n, da, av1, sizeof av1, 9000 + k, k == 6)); + settle(da); assert(cv_of(da)->nheld == 7 && !cv_of(da)->eos_pending); + for (int k = 0; k < 7; k++) assert(cv_of(da)->held_ts[k] == 9000 + k && cv_of(da)->held_eos[k] == (k == 6) && cv_of(da)->held[k]->d_w == 64); assert(!h_cv_av1fin(da) && !cv_of(da)); // The av1C record from a sequence header: profile 0, one operating point at level 12 (tier 0), 2560x1440, 8-bit 4:2:0 with chroma position 0, written field by field uint8_t obu[32] = {0x0a, 0}; size_t bit = 16; @@ -195,10 +234,32 @@ int main(void) { for (int soft = VTIsHardwareDecodeSupported(kCMVideoCodecType_AV1) ? 0 : 1; soft < 2; soft++) { setenv("DM_AV1_DAV1D", soft ? "1" : "0", 1); mav1 *a = mav1_new(); assert(!strcmp(mav1_backend(a), soft ? "dav1d" : "VideoToolbox")); - mav1_picture pic; assert(mav1_decode(a, av1, sizeof av1, &pic) == 1 && pic.w == 64 && pic.h == 64 && pic.matrix == 1 && !pic.full_range); // no matrix in the stream: BT.601 at 64 lines + // dav1d decodes several frames at once: a unit's picture comes with that unit's time, at once or when the frames in flight are asked for (mav1_next's drain). + // VideoToolbox gives each unit's picture as it takes the unit + mav1_picture pic; int got = mav1_decode(a, av1, sizeof av1, 4242, &pic); + if (!got) { assert(soft); got = mav1_next(a, 1, &pic); } + assert(got == 1 && pic.ts == 4242 && pic.w == 64 && pic.h == 64 && pic.matrix == 1 && !pic.full_range); // no matrix in the stream: BT.601 at 64 lines for (int y = 0; y < 64; y++) for (int x = 0; x < 64; x++) assert(abs(pic.y[(size_t)y * pic.ystride + x] - 81) <= 4); for (int y = 0; y < 32; y++) for (int x = 0; x < 64; x += 2) { assert(abs(pic.uv[(size_t)y * pic.uvstride + x] - 90) <= 6); assert(abs(pic.uv[(size_t)y * pic.uvstride + x + 1] - 240) <= 6); } - mav1_reset(a); assert(mav1_decode(a, delimiter, sizeof delimiter, &pic) == 0); // a new stream: nothing until its sequence header + assert(mav1_next(a, 1, &pic) == 0); // nothing more inside + // Key frames one after the other, with no picture asked for in between beyond what each call gives: every unit's picture comes out once, in order, with its time + int64_t want = 100; + for (int k = 0; k < 9; k++) { + for (int r = mav1_decode(a, av1, sizeof av1, 100 + k, &pic); r == 1; r = mav1_next(a, 0, &pic)) { assert(pic.ts == want && pic.w == 64); want++; } + if (k == 4) while (mav1_next(a, 1, &pic) == 1) { assert(pic.ts == want); want++; } // drained in the middle of the stream: it goes on after + } + while (mav1_next(a, 1, &pic) == 1) { assert(pic.ts == want && abs(pic.y[0] - 81) <= 4); want++; } + assert(want == 109); + // Drains at any point of the stream, each to its end, with one, two or three frames in flight: dav1d goes on after each (left halfway, a drain breaks it: dav1d_step) + uint32_t rng = 12345; int64_t sent = 1000; want = 1000; + for (int k = 0; k < 600; k++) { + for (int r = mav1_decode(a, av1, sizeof av1, sent++, &pic); r == 1; r = mav1_next(a, 0, &pic)) { assert(pic.ts == want); want++; } + rng = rng * 1664525u + 1013904223u; + if ((rng >> 28) < 5) { while (mav1_next(a, 1, &pic) == 1) { assert(pic.ts == want); want++; } assert(want == sent); } + } + while (mav1_next(a, 1, &pic) == 1) { assert(pic.ts == want); want++; } + assert(want == sent); + mav1_reset(a); assert(mav1_decode(a, delimiter, sizeof delimiter, 0, &pic) == 0 && mav1_next(a, 1, &pic) == 0); // a new stream: nothing until its sequence header mav1_free(a); } unsetenv("DM_AV1_DAV1D"); diff --git a/docs/agents/symptoms.md b/docs/agents/symptoms.md index 9db465e24f..0f536fa35d 100644 --- a/docs/agents/symptoms.md +++ b/docs/agents/symptoms.md @@ -408,6 +408,8 @@ One line per symptom in the [subsystem references](../reference/): what you see - on an iPad with an M1 (the one supported chip without I8MM), the app quits at the first AV1 movie (a title or opening movie): `[dm] CRASH sig=4 addr=put_8tap_neon_i8mm+0x… lr=dav1d_recon_b_inter_8bpc+0x…`, with a `dav1d_worker_task` thread beside it. The same build plays on an M2 or newer iPad, an A17 Pro or newer iPhone, and on the Mac. → [AV1 movies stop an M1 iPad with SIGILL in dav1d](../reference/movies.md#av1-movies-stop-an-m1-ipad-with-sigill-in-dav1d) - a Switch 2 game crashes when a movie starts: `nn::codec::video::Initialize` faults in the SDK (Donkey Kong Bananza: `sdk+0x2de99c`, after its first punch, when the guide movie starts), and before that `nv::InitCheck` aborts (`hle_nv.c`). Later, when a second movie starts: `game called nn::diag abort: Result 0` in `nn::os::ClearSystemEvent` or `TryWaitSystemEvent` on the decoder's event. → [`nn::codec` video decoders taken over](../reference/movies.md#nncodec-video-decoders-taken-over) - a movie stays black with the game waiting behind it, the decoder made and no `first picture` line (`Submit…InputBuffer` never called). Or `[RED] nn::codec VP9: Corrupt frame detected`, then `Keyframe / intra-only frame required`, each time about 6 s into a movie or after skipping in one. → [The submission-ready event counted as packets](../reference/movies.md#the-submission-ready-event-counted-as-packets) +- a movie stutters in small regular jerks (a picture stays for two or three frames, then the movie jumps on) while the frame rate reads a steady 60 and the frame times are flat: the game's frames are on time, the movie's pictures are not. Worst where the host decodes in software. → [`nn::codec` packets decoded inside the submission](../reference/movies.md#nncodec-packets-decoded-inside-the-submission) +- on a chip without a hardware AV1 decoder (M1, M2), a 1080p 60 fps AV1 movie shows a picture twice now and then in its heavy parts, with the decoder already on its own thread, and the log has `[codec] AV1 decoder 1: the decoder is behind the movie: of the last 600 packets decoded in … ms each, … ms the longest; … pictures came after their buffer was released`. → [dav1d decoded one frame at a time](../reference/movies.md#dav1d-decoded-one-frame-at-a-time) - a crash in `nn::codec::video::InitializeAv1DecoderByTransferMemory` when a movie starts. → [AV1 movies through SDK 22's decoder](../reference/movies.md#av1-movies-through-sdk-22s-decoder) - an abort in `nn::codec` (the SDK's own decoder client, which opens a service the host does not have) when a movie starts in a game built with SDK 19 for the Switch 2. → [SDK 19's decoder forms](../reference/movies.md#sdk-19s-decoder-forms) diff --git a/docs/reference/movies.md b/docs/reference/movies.md index 24bac40c5f..fe28b61b24 100644 --- a/docs/reference/movies.md +++ b/docs/reference/movies.md @@ -295,8 +295,8 @@ A decoder hands out as many outputs as it has slots, and while every slot is tak - **Symptom:** a Switch 2 game crashes when a movie starts: `nn::codec::video::Initialize` faults in the SDK (Donkey Kong Bananza: `sdk+0x2de99c`, after its first punch, when the guide movie starts), and before that `nv::InitCheck` aborts ([`hle_nv.c`](../../dm/gfx/hle_nv.c)). Later, when a second movie starts: `game called nn::diag abort: Result 0` in `nn::os::ClearSystemEvent` or `TryWaitSystemEvent` on the decoder's event. - **Cause:** the Switch 2's SDK decodes video through `nn::codec` (H.264, AV1, VP8, VP9 decoders over a decoder service, decoder image pools, NV12 / RGBA readback), not `movie::Decoder`; every call goes to a service the host does not serve. -- **Fix:** `dm/host/hle_codec_video.c` takes the API over: VP8 and VP9 decoded with libvpx (the YUV conversions of `hle_movie.c`, `hle_movie_yuv.h`), H.264 with VideoToolbox (`hle_movie_avc.c`, its NV12 pictures kept as I420, the parameter sets an Initialize overload passes given to it first). The four decoder types (`Vp8`, `Vp9`, `H264`, `Av1DecoderType`) have one layout, their event at +8 in the SDK, so one host decoder serves them (`cv_dec_*`, each family's entry points by their SDK names), `Unregister…DecoderBuffer` included. The protocol as the SDK implements it (sdk 20.5.19 Ounce): one image pool per output picture, registered with the decoder under an index; registering puts the index in an 8-deep queue of acquirable buffers with a signalled sync handle. `Release…OutputBuffer` gives the buffer to the decoder to fill and puts it back in the queue at once, with a new sync handle that signals when a picture is in it; `Acquire…OutputBuffer` takes the oldest (description 3604 when the queue is empty). `Get…OutputBufferProperties` gives size, time and end of stream once the buffer is filled (3604 until then). `Submit…InputBuffer` takes a packet (3603 while the decoder cannot take more, the client retries after the submission-ready event). On the host, packets decode on the submitting thread; pictures go into released buffers in release order, up to 4 wait for one. The sync handles are the host's (16 bytes: magic, decoder, index, generation): `nn::gs::TryWaitNativeSync` answers them, and so do sync point events (`nn::syncpt::sdk`, whose library the graphics initialisation sets up, which the host replaces: `CreateSyncPointEvent` jumped through a null table). A sync point event holds a SystemEvent the host binds, linked into the client's MultiWait by the SDK's own `nn::os::InitializeMultiWaitHolder`, and is signalled when its buffer is filled. The decoder's submission-ready event lives in the decoder type and goes with the decoder: `FinalizeVp9Decoder` destroys it, as the SDK does. Kept, it stayed in the host's table of bound SystemEvents, so the next decoder made in the same memory, which the game had cleared, was not given an event, and `nn::os::ClearSystemEvent` / `TryWaitSystemEvent` aborted on the uninitialised one (Donkey Kong Bananza, about four minutes in, when its second movie starts: two `nn::diag` aborts with Result 0, from `main+0xe1a71c` and `main+0x18793a0`). -- **Check:** `make -C dm/host/tests GAME= run` runs `t_codec_video` (AddressSanitizer and UBSan): the buffer queue and its results, sync handles and sync point events, NV12 / RGBA readback of a synthetic VP9 key frame, packets refused while 4 pictures wait, end of stream, flush, a pool finalized while its buffer is still registered, a decoder finalized and made again in the same cleared memory, a VP8 key frame, a 64×64 H.264 baseline key frame decoded by VideoToolbox (ffmpeg's libx264, SEI removed), an unregistered buffer and AV1's refused Initialize. +- **Fix:** `dm/host/hle_codec_video.c` takes the API over: VP8 and VP9 decoded with libvpx (the YUV conversions of `hle_movie.c`, `hle_movie_yuv.h`), H.264 with VideoToolbox (`hle_movie_avc.c`, its NV12 pictures kept as I420, the parameter sets an Initialize overload passes given to it first). The four decoder types (`Vp8`, `Vp9`, `H264`, `Av1DecoderType`) have one layout, their event at +8 in the SDK, so one host decoder serves them (`cv_dec_*`, each family's entry points by their SDK names), `Unregister…DecoderBuffer` included. The protocol as the SDK implements it (sdk 20.5.19 Ounce): one image pool per output picture, registered with the decoder under an index; registering puts the index in an 8-deep queue of acquirable buffers with a signalled sync handle. `Release…OutputBuffer` gives the buffer to the decoder to fill and puts it back in the queue at once, with a new sync handle that signals when a picture is in it; `Acquire…OutputBuffer` takes the oldest (description 3604 when the queue is empty). `Get…OutputBufferProperties` gives size, time and end of stream once the buffer is filled (3604 until then). `Submit…InputBuffer` takes a packet (3603 while the decoder cannot take more, the client retries after the submission-ready event). On the host, a submission queues its packet and each decoder decodes on its own thread ([below](#nncodec-packets-decoded-inside-the-submission)); pictures go into released buffers in release order, and up to 12 pictures and packets wait for one. The sync handles are the host's (16 bytes: magic, decoder, index, generation): `nn::gs::TryWaitNativeSync` answers them, and so do sync point events (`nn::syncpt::sdk`, whose library the graphics initialisation sets up, which the host replaces: `CreateSyncPointEvent` jumped through a null table). A sync point event holds a SystemEvent the host binds, linked into the client's MultiWait by the SDK's own `nn::os::InitializeMultiWaitHolder`, and is signalled when its buffer is filled. The decoder's submission-ready event lives in the decoder type and goes with the decoder: `FinalizeVp9Decoder` destroys it, as the SDK does. Kept, it stayed in the host's table of bound SystemEvents, so the next decoder made in the same memory, which the game had cleared, was not given an event, and `nn::os::ClearSystemEvent` / `TryWaitSystemEvent` aborted on the uninitialised one (Donkey Kong Bananza, about four minutes in, when its second movie starts: two `nn::diag` aborts with Result 0, from `main+0xe1a71c` and `main+0x18793a0`). +- **Check:** `make -C dm/host/tests GAME= run` runs `t_codec_video` (AddressSanitizer and UBSan): the buffer queue and its results, sync handles and sync point events, NV12 / RGBA readback of a synthetic VP9 key frame, packets refused while 12 pictures and packets wait, end of stream, flush, a pool finalized while its buffer is still registered, a decoder finalized and made again in the same cleared memory, a VP8 key frame, a 64×64 H.264 baseline key frame decoded by VideoToolbox (ffmpeg's libx264, SEI removed), an unregistered buffer and AV1's refused Initialize. - **Found on:** [Donkey Kong Bananza](../../dm/games/040074A01BF12000/README.md): 101 guide movies (`Movie/*.webm`, VP9 960×540, no sound); its player reads the pictures as NV12 (`ReadDecoderOutputImageNv12`, output format 3). - **Open:** AV1 (no decoder on the host: Initialize fails with a red line, so a client takes its error path instead of reaching the service), encrypted input, native image handles (the GPU route of decoded pictures), alias pools and the readback of part of a picture are not served (each prints a red line once). No game here plays VP8 or H.264 through this API yet: those paths are checked by the test only. Donkey Kong Bananza's player imports all four decoders; its movies are VP9. @@ -304,11 +304,32 @@ A decoder hands out as many outputs as it has slots, and while every slot is tak - **Symptom:** a movie stays black with the game waiting behind it, the decoder made and no `first picture` line (`Submit…InputBuffer` never called). Or `[RED] nn::codec VP9: Corrupt frame detected`, then `Keyframe / intra-only frame required`, each time about 6 s into a movie or after skipping in one. - **Cause:** [Mario Tennis Fever](../../dm/games/0400D4201C6EA000/README.md)'s player sends one packet per signal of the event it counts, and ignores `DecodeAsync`'s result (`nro0+0xd16130`), so each signal has to mean room for a packet. The host signalled at `Initialize`, which the player clears and drops while it is not started, and then only at releases. So nothing came after `Start`, and it never sent a packet. With a signal at `Start`, it then got one per release while a seek held back the samples, its count grew, and the host's refusal of a packet with 4 pictures waiting lost a frame for good: libvpx found everything after it corrupt until the next key frame. -- **Fix:** `Start…Decoder` signals (`cv_dec_start`). After that the event rises when a packet was taken or room came back, not at every release (`drain`), and goes down at 4 pictures waiting, while packets are refused only at 12 (`CV_READY`, `CV_HOLD`), so a signal in flight still finds room. -- **A refusal is no fault:** the refusal returns nn::codec 3603, which `NintendoSDK_movie` expects: `detail::SubmitDecoderInputBuffer` turns exactly that result into its own retry code 0x7a, which `VideoDecoder::DecodeAsync` hands back to its player, and aborts on any other failure (Ocarina of Time's `subsdk0` +0x10fd20, +0x103840). It is logged as `nn::codec : busy (result 3603), a packet refused …`, no longer as a red line (Ocarina of Time AV1, Kirby Air Riders VP9: 4 a run, movies play). A picture the host has to drop still prints `[RED] … one dropped`. +- **Fix:** `Start…Decoder` signals (`cv_dec_start`). After that the event rises when a packet was taken or room came back, not at every release (`ready`), and goes down at 4 waiting, while packets are refused only at 12 (`CV_READY`, `CV_HOLD`), so a signal in flight still finds room. What waits is counted the same whether a packet has been decoded yet or not: the pictures without a released buffer, the packets queued and the one in decode (`cv_pending`). +- **A refusal is no fault:** the refusal returns nn::codec 3603, which `NintendoSDK_movie` expects: `detail::SubmitDecoderInputBuffer` turns exactly that result into its own retry code 0x7a, which `VideoDecoder::DecodeAsync` hands back to its player, and aborts on any other failure (Ocarina of Time's `subsdk0` +0x10fd20, +0x103840). It is logged as `nn::codec : busy (result 3603), a packet refused …`, no longer as a red line (Ocarina of Time AV1, Kirby Air Riders VP9: 4 a run, movies play). The host drops no picture: the decoder's thread waits for room before it holds another (`cv_room`). - **Check:** `t_codec_video`. - **Found on:** [Mario Tennis Fever](../../dm/games/0400D4201C6EA000/README.md), every movie. +### `nn::codec` packets decoded inside the submission + +- **Symptom:** a movie stutters in small regular jerks (a picture stays for two or three frames, then the movie jumps on) while the frame rate reads a steady 60 and the frame times are flat: the game's frames are on time, the movie's pictures are not. Worst where the host decodes in software. +- **Cause:** the SDK's `Submit…InputBuffer` hands the packet to the decoder service and returns; the host decoded the packet inside the call, on the caller. A player that does all of a movie's work on one thread loses that thread for the length of each decode. Ocarina of Time's (in `main`) runs `DecodeAsync`, `AcquireVideoFrame` and `ReleaseVideoFrame` on its reader thread, and gives the shown picture's buffer back from there; its frame loop's `advance` (`main+0x3b61ea0`) keeps the picture on screen when no decoded frame is ready or the shown one has not been given back yet (the two failures at `main+0x3b61ed8`, `x8` zero or not). On an M2 Pro with dav1d, `DecodeAsync` took 1.9 ms at the median, 31 ms at the 90th percentile and 120 ms at the 99th, and `advance` failed in 546 and 569 of about 2,900 frames of the title (two runs; three in four of them or more with the picture not given back). The frame loop never waited, so the frame times showed nothing. +- **Fix:** each decoder decodes on a thread of its own (`cv_worker` in `hle_codec_video.c`), as `movie::Decoder` does ([Video decoded off the caller's thread](#video-decoded-off-the-callers-thread)). A submission copies its packet into the decoder's queue and returns (`cv_dec_submit`); the queue, the pictures waiting for a released buffer and the packet in decode count together for the submission-ready event and the refusal ([the event counted as packets](#the-submission-ready-event-counted-as-packets)), so a client sees the same event whatever the decoder's speed. The decoder's thread puts a picture into a released buffer and signals that buffer's sync point event itself (`hle_signal_system_event` is the host's, callable from any thread); with 12 pictures held it waits for a release before it decodes on. `Stop` and `Flush` drop the queued packets and the held pictures at once and number the stream anew, so the pictures of a packet still in decode are dropped when it ends; the codec is reset by its own thread before the next packet. Finalize joins the thread. Every guest call takes the decoder's lock as a host lock (`dm_host_mutex_lock`). +- **After:** `DecodeAsync` 0.10 / 0.20 / 1.1 ms, and 5 to 7 failed `advance` calls in about 2,900 frames with dav1d as it was; 0 or 1 with [dav1d on frame threads](#dav1d-decoded-one-frame-at-a-time). +- **Check:** `t_codec_video`: the event and the refusal are the same with the packets decoded or not, a submission signals its event itself and a sync point event comes from the decoder's thread, eight flushes with six undecoded packets each give only the key frame sent after them, and a decoder is finalized with six packets undecoded. +- **Found on:** [The Legend of Zelda: Ocarina of Time](../../dm/games/0400486024DEC000/README.md), its title movie (AV1, 1920x1080 at 60 fps) on an M2 Pro, headless, with `DM_PROBE=main:3b61ed8,main:3b61f80` counting the failed and the good `advance` calls. +- **Open:** the other games that decode through `nn::codec` (Donkey Kong Bananza, Mario Kart World, Mario Tennis Fever, Kirby Air Riders, Fire Emblem Fortune's Weave) were not run with it: none of them was on the Mac it was written on. + +### dav1d decoded one frame at a time + +- **Symptom:** on a chip without a hardware AV1 decoder (M1, M2), a 1080p 60 fps AV1 movie shows a picture twice now and then in its heavy parts, with the decoder already on its own thread, and the log has `[codec] AV1 decoder 1: the decoder is behind the movie: of the last 600 packets decoded in … ms each, … ms the longest; … pictures came after their buffer was released`. +- **Cause:** dav1d was opened with two task threads and `max_frame_delay` 1: one frame at a time, so that a temporal unit's picture was there when its send returned. A hierarchical stream puts several frames in one temporal unit (the hidden ones the next units only show): Ocarina of Time's title movie took 80 to 122 ms for one unit in about 32 on an M2 Pro, and 15.4 ms a unit over its heaviest five seconds, at a budget of 16.7 ms. More task threads alone gave nothing (4 threads on one frame: the same times). +- **Fix:** dav1d decodes on 4 threads, 3 frames at once (`DAV1D_THREADS`, `DAV1D_FRAMES` in `hle_movie_av1.c`): 7.1 ms a unit over the same five seconds and 42 to 76 ms the longest (2 frames at once 8.8 ms; 6 threads on 3 frames no better). Its pictures now come out later than their units go in, so each unit's time rides with it (`Dav1dData.m.timestamp`, `mav1_picture.ts`) and the decoder's thread asks for more pictures after a unit (`mav1_next`). When no packet waits behind a unit, and at the end of the stream, it drains dav1d, so a picture is not kept back for a packet that may not come. +- **A drain goes to its end:** a `dav1d_get_picture` with no data sent before it is dav1d's drain (`drain_picture`, `lib.c`, 1.5.4), which steps over its empty frame contexts on the way to the oldest frame. Data sent between two such calls leaves `frame_thread.next` on a frame still in flight; that frame is then retired with `task_thread.first` one context past the oldest for good, and retiring a frame cancels the task rescan asked for `task_thread.first` (`reset_task_cur`), now a live frame's. Its task is never run: the workers sleep in `dav1d_worker_task` and `dav1d_submit_frame` waits for ever. With a drain that stopped as soon as a packet arrived, the title movie froze for good in 3 runs of 6 (`sample`: `dm codec video` in `dav1d_submit_frame`, the four workers parked). A drain that has given a picture is now called until it gives none (`mav1_next`'s contract; `decode_dav1d` ends one left open, with a red line). +- **Check:** `t_codec_video` sends AV1 key frames through the protocol and gets each with its own time, in order, the last with the end of stream; it drains mid-stream, and runs 600 rounds of units with drains at random places. +- **Found on:** [The Legend of Zelda: Ocarina of Time](../../dm/games/0400486024DEC000/README.md): eight runs of the title on an M2 Pro (54 s each, headless, the player's settings), 0 or 1 failed `advance` in 2,567 to 3,036 a run (none in six of them) and no frozen movie; before both fixes, 546 and 569 failed. In a window, over 88 s of the title movie: 5,273 packets decoded in 4.82 ms each, 87 ms the longest, 2 pictures after their buffer was released (the totals line at Finalize). +- **The log line:** the decoder's thread counts the pictures that found a released buffer already waiting for them (the client had run out of decoded pictures) and times each packet (`cv_stat`). A run of 600 packets with more such pictures than the decoder has buffers prints the line above; Finalize prints the totals. On the title movie: 0 to 3 in a run with frame threads, 29 and 18 in the two heaviest without, where `advance` failed 5 to 7 times. +- **Open:** measured on an M2 Pro only (8 performance cores). An M1 or M2 with 4 performance cores, and an M1 or M2 iPad, were not run; there the log line says whether the decoder keeps up. + ### AV1 movies through SDK 22's decoder - **Symptom:** a crash in `nn::codec::video::InitializeAv1DecoderByTransferMemory` when a movie starts.