diff --git a/CLAUDE.md b/CLAUDE.md index 04e3754..19d8e76 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -287,9 +287,11 @@ platform types it touches, and walks it over the shapes that set has actually produced: a rung that hangs, a rung a previous launch never came back from (once, which is asked again, and twice, which is a refusal), a ledger left by another build, a ledger that never opens, a page loaded before the walk, an install whose -ledger says the engine already failed there (the walk goes ahead of the engine), and -a clean run twice over. It needs a C compiler for the stand-in library and nothing -else. +ledger says the engine already failed there (the walk goes ahead of the engine), a +clean run twice over (the second walk finds the verdict on the books and asks +nothing — issue #105's set ended two launches on the first rung of a walk behind a +verdict), and a walk started behind the early one on the same launch. It needs a C +compiler for the stand-in library and nothing else. The ladder's only real property is that it converges — whatever one rung does, the rungs and locations behind it still get asked. Two builds have been spent finding out @@ -312,9 +314,11 @@ builds a library in this box's own architecture that needs `libm`, `libc` and a `libblocked.so` made unopenable by permission, and holds the census to naming exactly the blocked library's two symbols (a function and a data object), the refusal with the loader's words, nothing that another library provides, and no -weak import. The committed ARM `libovprobe.so` exercises the ELF32 path, a FIFO -holds it to a recorded miss rather than a hang, and a second call must change -nothing. Needs the .NET 6 SDK under `~/.dotnet-local` and a C compiler. +weak import — taken inline and again on a thread of its own with the caller +waiting, which is how `OnCreate` runs it ahead of the engine. The committed ARM +`libovprobe.so` exercises the ELF32 path, a FIFO holds it to a recorded miss rather +than a hang, and a second call must change nothing. Needs the .NET 6 SDK under +`~/.dotnet-local` and a C compiler. ### The trail harness diff --git a/docs/INTERNALS.md b/docs/INTERNALS.md index 7cebb7f..31c815f 100644 --- a/docs/INTERNALS.md +++ b/docs/INTERNALS.md @@ -1211,10 +1211,71 @@ reversal later: never arrives — the set parks the census like the Q80 parked its calls; the previous-run block says which step. -**State of #105 (2026-10-02):** the ladder's answer is in and is the good one; the -census shipped in `build-283f3e9`, and the reply asking the reporter to run it quotes -that tag. Nothing here changes the Q80's close: -that set refused the mapping the AU7200 allows. +### The census has to go ahead of the engine too + +The `build-283f3e9` report (2026-10-02, the same afternoon) has no `engine imports:` +line on it, and the trail says why. Its previous-run block is the build's first +launch: the early walk reached its verdict in 248 ms, the engine failed line for line +as before, and then the post-failure thread **started the walk again** — the ledger's +answers replayed, `probe: copy libovprobe.so to data/`, `probe: open res/` — and that +is the launch's last line. No `read header` behind it, no deadline miss five seconds +later, no `still on the failure screen — +10s` from the heartbeat. The launch was over +within five seconds of `ENGINE FAILURE`: the Q80's shape (*The ladder has to start*, +above), on a set that otherwise answers every call we make. The census was queued +behind that second walk and never reached. + +The `this run` block — the second launch, 23 s later — is three lines with no UI: +`Main entered`, the socket, the engine preload. The `build-3996334` page had the same +three lines at the same place, fetched minutes after launch both times, so this is not +a quick reporter: **on this set the second launch of a build stops before or inside +`Elementary.Initialize()`** and the only page it ever serves is the no-provider page. +That page had no `build :` line, though the reply had promised one, and nothing of the +census. + +Four things follow and are in the code: + +- **A walk behind a verdict asks nothing.** `NativeProbe.Walk` reads the verdict + after `Ledger.Open` and returns on it: `native probe: verdict already on the books + — …; not walking again`. The repeatable rungs (`open`, `header`, `read`, the copy + into `data/`) were re-made on every walk so the rungs behind them had a descriptor; + behind a verdict there are no rungs, and on this set the first of them was where + the launch ended with the census behind it. `tools/probeladder`'s `resume`, `peek`, + `early` and `notearly` hold it; `peek` used to assert the opposite. +- **The census goes ahead of the engine, on the walk's gate.** + `NativeProbe.EngineFailedHere()` is true whenever a ledger exists, which it only + does on an install whose engine has failed. `OnCreate` then runs + `EngineImports.RunInBackground` after the walk and waits up to 60 s for it + (`engine imports: the engine waits for the census (up to 60 s)` … `census finished + after N ms — on to the engine`), the way it waits for the walk; every dlopen in it + is under its own deadline, and what the bound cuts off still reaches the trail from + the census's thread. The lines go to the trail as they are established, because + the page that shows them is the *next* launch's. The post-failure call stays for + the first failure on an install and finds the census taken on every launch after. + `tools/engineimports`'s `background` scenario drives this shape, and found the + claim race in the first version of it. +- **The no-provider page carries `build :`, `engine imports:` and the stub block**, + because on this set every page is that page. +- **`Program.Main` drops `Elementary: initializing` before the call**, so the second + launch's three lines become four and name the call they stop in front of. + +How to read the next report, in addition to the four readings above: the +previous-run block should carry, between `OnCreate: UI built` and `EFL subsystems`, +the walk's verdict (early or already on the books), then `engine imports: the engine +failed on an earlier launch here — taking the census now, ahead of the engine`, +`reading /usr/share/chromium-efl/lib/libchromium-impl.so`, the `ELF32 … needed, … +imports (… weak)` counts line, one `refused` line per library the loader would not +open, and the `N unresolved` line with up to forty names. A `DID NOT RETURN` on the +read is the set parking the census; `still counting after 60 s` with lines behind it +is a slow set, and the lines are still the answer. The reply also asks what the +screen showed on the second open: a failure screen that never came is the second +finding above, and the no-provider page is then the only page this set will ever +serve, which the reporter's instructions have to say. + +**State of #105 (2026-10-02, evening):** the ladder's answer is in and is the good +one; `build-283f3e9` shipped the census and the AU7200 never reached it; the build +after it takes the census ahead of the engine and is the one the stub depends on. The +reply quotes that tag. Nothing here changes the Q80's close: that set refused the +mapping the AU7200 allows. ### `ELM_ACCEL` has to be set before the window exists @@ -3254,17 +3315,36 @@ the one its report has to come from. The state is: three seconds before, paused the whole time. The fix is `NuiMseHold` (see *One video at a time*): the next reel's source is held back until TikTok plays it, so no second pipeline opens under the one on screen. Menu row to - switch it off. Shipped in `build-644c119`. **Waiting on:** his report from - that build, after a few reels. The trail answers it in three lines per reel: `hold - v2 blob while v1 plays`, then on the swipe `release v2 after Ns (play)`, - then the probe's `v2 playing`. Reels that play to the end with that sequence - is the fix. A `release` with no `playing` after it, or the next reel sitting - on its spinner, is TikTok's player waiting for the preload to be ready - before it will swap — the hold would then have to let the attach through and - the fallback is the automatic pause/play on the frozen reel, which recovers - after a freeze he would still see. Reels still freezing with `held 0` on the - `one video :` line is TikTok attaching by a path the hold does not see, and - the probe's `loadstart` line (`blob not ours`, `srcObject`) says which. + switch it off. Shipped in `build-644c119`. **His report from it (2026-10-02): + "if next is normal videos never freeze"**, and the one freeze left comes + "sometimes, if the next video is a live stream". Two trails. The one without a + freeze has TikTok's swipe as an element swap — `hold v2 blob while v1 plays`, + `v1 playing` two seconds later, v1 then playing for three minutes — and never + a release, because v1 had been readied before the script was in the page. The + one with the freeze has the hold doing exactly what it was built to do (`hold + v1 blob while v2 plays` at 17:08:19, `release v1 after 122.6s (play)` at + 17:10:22, `v1 playing` three seconds after that) and, four seconds after the + hold, a path it does not cover: TikTok **emptied the on-screen element and + gave it a new source** — `v2 emptied`, `v2 loadstart blob not ours`, a new + MediaSource `ms4` at the same 768x576 — and v2 sat `rs0 starved stuck` for + thirteen seconds before it played, then paused and resumed every few seconds + for two minutes. Those pauses are the page's own: nothing of ours calls + `pause` or `play` but `NuiVideoCap`, and it ran zero times on both trails. + Whether the re-sourced v2 was the live stream, or a reel TikTok loaded cold into + the element on screen because the held one was not ready, the trail cannot say: + it had no duration and no address. The build after `build-644c119` adds both + to the probe's lines, read-only: `loadedmetadata 768x576, dur inf` (`inf` is + what a live stream reads, and also what an MSE clip reads until its page sets + a duration — `inf` with a playhead that never loops back is live) and + `, live page` on `loadstart` and `playing` while the address is `/@user/live`. + **Waiting on:** his report from that build with a freeze on it. `live page` or + `dur inf` on the re-sourced element is the live stream itself stalling, and a + live stream cannot buffer ahead: that is the proxy's throughput, the hold is + doing its job, and the answer is that live streams through that proxy will + stall. A finite `dur` on a `/video/` page with a `hold` a few seconds before is + TikTok loading into the on-screen element because the held one was not ready + — the hold would then have to release when the element on screen is emptied, + which is the next fix and a `tools/msehold` case before it is one. Five things about that set are settled and should not be re-derived: **key `5` is his, not ours** — the engine's overlay path is the only one that gives him a diff --git a/src/common/DiagServer.cs b/src/common/DiagServer.cs index 5fa81c7..fa513f9 100644 --- a/src/common/DiagServer.cs +++ b/src/common/DiagServer.cs @@ -99,10 +99,24 @@ private static string Report() // The probe's ledger outlives a launch, and the header line is the // one a reporter copies first — so it is here too, on the page they // get when the UI is not up yet. + // + // The build tag and the import census too (issue #105): on the AU7200 + // every page has been this one, because the first launch of a build + // dies within seconds of the engine failing and the second never + // reaches the UI. The `build-283f3e9` reply told the reporter the + // page would start with `build :`, and it did not — this page had no + // such line — which is a round trip spent on doubt about which + // build was installed. What this page cannot show is what the + // *current* launch has not yet established; the census it carries + // is this launch's if it has run, and the previous run's lines are + // in the trail below. return "Overscan — no report provider yet (UI has not started)\n\n" + + "build : " + BuildInfo.Tag + "\n" + "own native : " + NativeProbe.Summary + "\n" + + "engine imports: " + EngineImports.Summary + "\n" + "trail write: " + Breadcrumbs.Status + "\n\n" + "this run\n" + DiagLog.Dump() + + "\nwhat a stub must provide (the implementation's imports)\n" + EngineImports.Dump() + "\nprevious run (last line is where it died)\n" + Breadcrumbs.Previous + "\nengine stdout/stderr (previous run)\n" + diff --git a/src/common/EngineImports.cs b/src/common/EngineImports.cs index 29aedbc..b693f0e 100644 --- a/src/common/EngineImports.cs +++ b/src/common/EngineImports.cs @@ -4,6 +4,7 @@ using System.IO; using System.Runtime.InteropServices; using System.Text; +using System.Threading; namespace Overscan { @@ -35,12 +36,24 @@ namespace Overscan /// load. Whatever is still unresolved is what the stub has to provide, by name. /// /// Each step past managed code goes out under a , because - /// a call this firmware objects to is parked rather than refused, and it runs on - /// the post-failure probe thread after the engine has already failed: whatever - /// is most likely not to survive the firmware goes last. It is placed ahead of - /// the permission investigation on that thread because the investigation's last - /// step is the one the Q80 never came back from, and this census is the question - /// the next build is waiting on. + /// a call this firmware objects to is parked rather than refused. + /// + /// Where it runs was decided by the `build-283f3e9` report (2026-10-02). That build + /// put the census on the post-failure probe thread, behind the ladder's walk and + /// ahead of the permission investigation, and the census never ran: the launch + /// ended within five seconds of `ENGINE FAILURE` — no heartbeat tick, no deadline + /// miss — with the thread still on the walk's first repeatable rung. That is the + /// Q80's shape exactly (see NativeProbe.StartEarlyIfUnfinished): on these + /// sets a launch whose engine has failed is over before anything queued behind + /// the failure gets a turn, and the second launch of the same build never reached + /// the UI at all. So, like the walk, the census goes **ahead of the engine** on + /// an install whose ledger already says the engine fails here + /// (NativeProbe.EngineFailedHere), after the walk if one is due, and the + /// engine waits for it, bounded. On every set this app works on there is no + /// ledger and none of this runs. The post-failure call is still made, for the + /// first failure on an install, and finds the census already taken on the rest. + /// Its lines go to the trail as they are established, because the page that + /// shows them is served by the *next* launch, before its UI exists. /// /// How to read it: a short list of plain C function names is a no-op stub, /// buildable with the same toolchain recipe as `libovprobe.so`. C++ names (`_Z…`) @@ -76,6 +89,9 @@ internal static class EngineImports private static readonly List Lines = new List(); private static bool _ran; + /// Set whenever no census is running; reset while one is. + private static readonly ManualResetEvent Finished = new ManualResetEvent(true); + /// One line for the diagnostics header. public static string Summary { get; private set; } = "(not asked)"; @@ -115,17 +131,36 @@ private static void Trace(string line) /// Never throws: a diagnostic has nobody to throw to. /// public static void Census(string implementation, string blocked) + { + if (Claim()) + { + Take(implementation, blocked); + } + } + + /// + /// Takes the one census this process gets, for whichever caller is first; + /// false for every caller after. The wait event is reset here, under the + /// same lock, so a caller that starts the census on a thread and then waits + /// cannot see the event still set from before the thread got going. + /// + private static bool Claim() { lock (Gate) { if (_ran) { - return; + return false; } _ran = true; + Finished.Reset(); + return true; } + } + private static void Take(string implementation, string blocked) + { try { Run(implementation, blocked); @@ -135,6 +170,62 @@ public static void Census(string implementation, string blocked) Summary = "threw " + ex.GetType().Name + ": " + ex.Message; Trace(Summary); } + finally + { + try + { + Finished.Set(); + } + catch (Exception) + { + // Nobody to tell. + } + } + } + + /// + /// on a thread of its own, for the launch that runs it + /// ahead of the engine: the caller waits with , + /// bounded, and a census still going when the bound passes carries on while + /// the engine is asked — its lines reach the trail either way. Claimed here, + /// before the thread exists, so the post-failure call finds it taken. + /// + public static void RunInBackground(string implementation, string blocked) + { + if (!Claim()) + { + return; + } + + try + { + var thread = new Thread(delegate () { Take(implementation, blocked); }); + thread.IsBackground = true; + thread.Name = "engine-imports"; + thread.Start(); + } + catch (Exception ex) + { + // A set that will not give us a thread gets asked the dangerous way. + Trace("no thread (" + ex.GetType().Name + "), taking the census inline"); + Take(implementation, blocked); + } + } + + /// + /// Waits for a census started by to finish, for + /// at most . True if it did (or none is running). + /// + public static bool WaitForCensus(int timeoutMs) + { + try + { + return Finished.WaitOne(timeoutMs); + } + catch (Exception) + { + return false; + } } private static void Run(string implementation, string blocked) diff --git a/src/common/NativeProbe.cs b/src/common/NativeProbe.cs index 88302ea..f1ff697 100644 --- a/src/common/NativeProbe.cs +++ b/src/common/NativeProbe.cs @@ -625,6 +625,18 @@ private static string Watched(string step, Func call) /// returned. The page was loaded a second after launch, which is a /// reasonable thing to do and has now cost two rounds of somebody's evening. /// + /// The verdict on the books, from this launch or an earlier one, or null. + public static string Verdict + { + get + { + lock (Book) + { + return _verdict; + } + } + } + public static string Progress() { lock (Book) @@ -844,6 +856,10 @@ private static void Append(string path, string line) /// question is queued behind it. They are ledgered too, which is what makes /// them collectable at all: a hang on the first location used to eat every /// reading behind it, on every launch, forever. + /// + /// A walk whose verdict is already on the books — from an earlier launch, or + /// from the early walk on this one — says so and asks nothing; see the note + /// in . /// public static void Run() { @@ -932,13 +948,7 @@ public static bool WaitForWalk(int timeoutMs) /// public static bool StartEarlyIfUnfinished() { - string directory = DataDirectory(); - if (string.IsNullOrEmpty(directory)) - { - return false; - } - - string outcome = Ledger.Standing(Path.Combine(directory, LedgerFile)); + string outcome = Standing(); if (!outcome.StartsWith("unfinished", StringComparison.Ordinal)) { return false; @@ -950,6 +960,40 @@ public static bool StartEarlyIfUnfinished() return true; } + /// + /// Where the ladder stands on this install, read from the ledger and never + /// written: "no ledger" (every set this app works on), "finished", + /// "unfinished", "unfinished — another build's ledger", or the deadline's + /// miss. One small file read, under the deadline. + /// + public static string Standing() + { + string directory = DataDirectory(); + if (string.IsNullOrEmpty(directory)) + { + return "no ledger"; + } + + return Ledger.Standing(Path.Combine(directory, LedgerFile)); + } + + /// + /// Whether the engine has already failed on this install: the ledger only + /// ever comes into existence on a launch whose engine had failed, so its + /// presence is that record, whatever build wrote it and whether or not the + /// walk finished. This is the gate for every diagnostic allowed in front of + /// the engine — the walk when it is unfinished, and the import census + /// (issue #105) whenever the ledger is there at all — because on an install + /// where the books already say the engine fails, a launch spent + /// re-establishing that is a launch spent on nothing. + /// + public static bool EngineFailedHere() + { + string outcome = Standing(); + return string.Equals(outcome, "finished", StringComparison.Ordinal) || + outcome.StartsWith("unfinished", StringComparison.Ordinal); + } + /// /// on a background thread. The walk is claimed here, before /// the thread exists, so a that follows on another thread @@ -1014,6 +1058,25 @@ private static void Walk() Trace(" probe ledger: none — a fatal step will not be skipped next launch"); } + // A verdict on the books is the answer, and nothing behind this line + // can improve on it — so the walk stops here rather than re-asking + // the repeatable rungs. The AU7200 (issue #105) showed why that + // matters: on `build-3996334` and `build-283f3e9` alike the early walk + // reached its verdict in a quarter of a second, the engine failed, + // the post-failure thread started the walk *again*, and the launch + // ended at `probe: open res/` — the first repeatable rung — with the + // import census queued behind it and never reached. On that set + // every launch is over within five seconds of the engine failing + // (no heartbeat, no deadline miss), so whatever sits in front of a + // question on the failure path is what costs that question a build. + string settled = Ledger.Verdict; + if (settled != null) + { + Summary = settled; + Trace("native probe: verdict already on the books — " + settled + "; not walking again"); + return; + } + // Before the first question, and again after every location: both // reports on build-3368aea were pages loaded a second after launch, and // they read `own native : (not asked)` on a set whose trail plainly diff --git a/src/common/SmackWall.cs b/src/common/SmackWall.cs index 0326cc4..4629eb3 100644 --- a/src/common/SmackWall.cs +++ b/src/common/SmackWall.cs @@ -180,8 +180,12 @@ public static void InvestigateInBackground(string target) // Issue #105: what a stub would have to export, ahead of the // investigation because the investigation's last step is the - // one the Q80 never came back from, and this is the question - // the next build on a set that passed the ladder waits on. + // one the Q80 never came back from. On an install whose ledger + // already records the engine's failure the census was taken + // ahead of the engine, from OnCreate, and this call finds it + // done; this is the first failure's path. build-283f3e9 had it + // here only, and the AU7200's launch was over before the walk + // in front of it finished — see EngineImports. EngineImports.Census(ChromiumImpl.Implementation, target); Investigate(target); }); diff --git a/src/elm/BrowserApp.cs b/src/elm/BrowserApp.cs index 0a10951..53b68c9 100644 --- a/src/elm/BrowserApp.cs +++ b/src/elm/BrowserApp.cs @@ -175,6 +175,7 @@ protected override void OnCreate() // ladder is done. Bounded, because a set that stalls every rung would // otherwise hold a black screen for four minutes; the ledger carries the // rest to the next launch. See NativeProbe.WaitForWalk. + bool engineFailedHere = NativeProbe.EngineFailedHere(); if (NativeProbe.StartEarlyIfUnfinished()) { const int WalkBudgetMs = 90000; @@ -187,6 +188,32 @@ protected override void OnCreate() : "native probe: still walking after " + (WalkBudgetMs / 1000) + " s — on to the engine anyway"); } + // The second diagnostic allowed in front of the engine, on the same + // grounds and the same gate (issue #105). build-283f3e9 took the import + // census on the post-failure thread and the AU7200 never got there: the + // launch was over within five seconds of ENGINE FAILURE, as every Q80 + // launch was, and the second launch of the build never reached this + // method. On an install whose ledger already records the engine's + // failure, the census runs here, after the walk, and the engine waits + // for it — bounded, because each of the implementation's hundred-odd + // dependencies is a dlopen under its own deadline, and a set that parks + // them all would otherwise hold a black screen for minutes. What the + // bound cuts off still reaches the trail from the census's own thread. + // See EngineImports for what the lines mean. + if (engineFailedHere) + { + const int CensusBudgetMs = 60000; + Breadcrumbs.Drop("engine imports: the engine failed on an earlier launch here — taking the census now, ahead of the engine"); + EngineImports.RunInBackground(null, null); + Breadcrumbs.Drop("engine imports: the engine waits for the census (up to " + + (CensusBudgetMs / 1000) + " s)"); + var censusClock = System.Diagnostics.Stopwatch.StartNew(); + bool counted = EngineImports.WaitForCensus(CensusBudgetMs); + Breadcrumbs.Drop(counted + ? "engine imports: census finished after " + censusClock.ElapsedMilliseconds + " ms — on to the engine" + : "engine imports: still counting after " + (CensusBudgetMs / 1000) + " s — on to the engine anyway"); + } + // Bringing up chromium-efl is the one step we expect to be able to // fail: there are reports of an app-created Tizen.WebView crashing on // the TV emulator with nothing in the log, and the TV profile is not diff --git a/src/elm/Program.cs b/src/elm/Program.cs index 213a203..2fcfeec 100644 --- a/src/elm/Program.cs +++ b/src/elm/Program.cs @@ -59,6 +59,13 @@ private static void Main(string[] args) // Required before any ElmSharp widget is created (the Tizen.WebView // sample in TizenFX does the same). ElmSharp is deprecated from API // 10, so on a newer platform this is a place that can fail. + // + // Named before it is made, like every call that has ever stopped a + // launch. On the AU7200 (issue #105) the second launch of each build + // has shown three lines and no UI, on two builds; the last of them is + // the preload's, which puts this call next in line, by inference + // only. This line makes it the trail's statement rather than ours. + Breadcrumbs.Drop("Elementary: initializing"); Elementary.Initialize(); Elementary.ThemeOverlay(); Breadcrumbs.Drop("Elementary initialized"); diff --git a/src/nui/NuiMseWatch.cs b/src/nui/NuiMseWatch.cs index 6518632..291e2c0 100644 --- a/src/nui/NuiMseWatch.cs +++ b/src/nui/NuiMseWatch.cs @@ -421,6 +421,28 @@ function onScreen(v) { } catch (e) { return '?'; } } + /* How long the element says its media is: a number is a clip, `inf` is what a + live stream reads — and also what an MSE clip reads until its page sets + MediaSource.duration, so `inf` on its own is not live; `inf` with a playhead + that never loops back to 0 is. Issue #100's `build-644c119` reports: the one + freeze left is said to come with a live stream next in the feed, and nothing + on the trail could say which element had the live stream in it. */ + function dur(v) { + try { + var d = v.duration; + return 'dur ' + (isFinite(d) ? d.toFixed(1) + 's' : 'inf'); + } catch (e) { return 'dur ?'; } + } + + /* TikTok's feed moves the address to /@user/live while a live stream is the + item on screen, which is the one plain statement of it there is. Nothing + else about the page is read, and nothing when it is not that page. */ + function where() { + try { + return /\/live(\/|$)/.test(location.pathname) ? ', live page' : ''; + } catch (e) { return ''; } + } + ['loadstart', 'loadedmetadata', 'playing', 'waiting', 'pause', 'emptied'].forEach(function (type) { document.addEventListener(type, function (e) { try { @@ -429,10 +451,10 @@ function onScreen(v) { var g = tag(v); g.ev = type; g.at = Date.now(); - var what = type === 'loadstart' ? origin(v) + ', preload ' + v.preload + ', ' + onScreen(v) - : type === 'loadedmetadata' ? v.videoWidth + 'x' + v.videoHeight + ', ' + onScreen(v) + var what = type === 'loadstart' ? origin(v) + ', preload ' + v.preload + ', ' + onScreen(v) + where() + : type === 'loadedmetadata' ? v.videoWidth + 'x' + v.videoHeight + ', ' + dur(v) + ', ' + onScreen(v) : type === 'emptied' ? onScreen(v) - : 't ' + v.currentTime.toFixed(1) + ', ' + onScreen(v); + : 't ' + v.currentTime.toFixed(1) + ', ' + onScreen(v) + (type === 'playing' ? where() : ''); report(g.id + ' ' + type + ' ' + what); } catch (_) {} }, true); diff --git a/tools/engineimports/Program.cs b/tools/engineimports/Program.cs index 2d7f470..39753a3 100644 --- a/tools/engineimports/Program.cs +++ b/tools/engineimports/Program.cs @@ -31,7 +31,22 @@ private static int Main(string[] args) string blocked = args.Length > 2 ? args[2] : null; var started = DateTime.UtcNow; - EngineImports.Census(path, blocked); + if (scenario == "background") + { + // The shape OnCreate uses ahead of the engine (issue #105): the census + // on its own thread, the caller waiting, bounded. Same answers as + // the inline call, and a Census behind it must find it taken. + EngineImports.RunInBackground(path, blocked); + Expect(EngineImports.WaitForCensus(60000), "the census on its own thread finishes inside the wait"); + Expect(EngineImports.WaitForCensus(0), "a wait after it returns at once"); + scenario = "census"; + } + else + { + Expect(EngineImports.WaitForCensus(0), "before any census, a wait returns at once"); + EngineImports.Census(path, blocked); + } + double seconds = (DateTime.UtcNow - started).TotalSeconds; string summary = EngineImports.Summary; diff --git a/tools/engineimports/run.sh b/tools/engineimports/run.sh index 302b931..f19d4a1 100755 --- a/tools/engineimports/run.sh +++ b/tools/engineimports/run.sh @@ -67,6 +67,9 @@ run() { # set says "Operation not permitted", and the census only has to carry the words. chmod 000 "$work/lib/libblocked.so" run census "$work/lib/libneedy.so" libblocked.so +# The same, taken on a thread of its own with the caller waiting — how OnCreate +# runs it ahead of the engine. +run background "$work/lib/libneedy.so" libblocked.so chmod 644 "$work/lib/libblocked.so" # Nothing to import at all, on the committed ARM ELF32. diff --git a/tools/msewatch/build-page.py b/tools/msewatch/build-page.py index c9e9d44..8e1a2ee 100644 --- a/tools/msewatch/build-page.py +++ b/tools/msewatch/build-page.py @@ -138,9 +138,14 @@ def script(): Object.defineProperty(fake, 'currentTime', {get:function(){ return T; }, set:function(){ fake.__touched = 'seek'; }}); Object.defineProperty(fake, 'src', {get:function(){ return url; }}); Object.defineProperty(fake, 'currentSrc', {get:function(){ return url; }}); +Object.defineProperty(fake, 'duration', {get:function(){ return Infinity; }}); fake.getVideoPlaybackQuality = function(){ return {totalVideoFrames: 40, droppedVideoFrames: 0}; }; ['pause','play','load'].forEach(function(f){ fake[f] = function(){ fake.__touched = f; }; }); document.body.appendChild(fake); +/* Metadata the way a live stream reports it — no finite duration. The real MSE + element above never reaches metadata (its segments are shells), so this is the + one loadedmetadata the run has, and the probe has to read the duration off it. */ +setTimeout(function(){ fake.dispatchEvent(new Event('loadedmetadata')); }, 1500); setTimeout(function(){ setInterval(function(){ T += 0.25; }, 250); }, 5000); function has(re){ return mse.some(function(l){ return re.test(l); }); } @@ -165,6 +170,8 @@ def script(): if (!has(/^moving again v\\d after \\d+\\.\\ds \\(on its own\\), frames \\+0, appends \\+0$/)) { fail('end of stall not reported'); } if (has(/avc1 0x0/)) { fail('the ftyp brand list was read as a sample entry'); } if (!has(/^v\\d loadstart ms1, preload \\w+, (on|off) screen$/)) { fail('MSE element loadstart not reported with its source'); } + if (!has(/^v\\d loadedmetadata \\d+x\\d+, dur inf, (on|off) screen$/)) { fail('loadedmetadata not reported with the duration'); } + if (has(/live page/)) { fail('a page that is not /live was called one'); } if (!has(/^v\\d loadstart url example\\.invalid\\/video, preload auto, (on|off) screen$/)) { fail('plain-URL element loadstart not reported'); } if (!has(/^with v\\d paused rs\\d ns\\d url example\\.invalid\\/video, (on|off) screen|no box, last \\w+ \\d+\\.\\ds ago$/)) { fail('stall does not list the plain-URL element'); } if (!has(/^with v\\d paused rs\\d ns\\d ms1, /)) { fail('stall does not list the other MSE element'); } diff --git a/tools/probeladder/Program.cs b/tools/probeladder/Program.cs index 356e69b..a35b835 100644 --- a/tools/probeladder/Program.cs +++ b/tools/probeladder/Program.cs @@ -151,31 +151,44 @@ private static void Peek(string root) NativeProbe.Run(); - Expect(NativeProbe.Summary.Contains("maps executable and dlopen loaded it"), - "a walk behind it replaces the verdict with this box's own"); + // Until the AU7200's two reports a walk behind a verdict replaced it with + // this launch's own. It asks nothing now — see Resume — so the seeded + // verdict stands, on the header and on the file, and nothing is written + // after it. + Expect(NativeProbe.Summary == before, "a walk behind it keeps the verdict rather than asking again"); + Expect(Breadcrumbs.Trail.Contains("verdict already on the books — " + before), "and says why"); string ledger = Ledger(root); - Expect(ledger.IndexOf("verdict\t" + NativeProbe.Summary, StringComparison.Ordinal) > - ledger.IndexOf("verdict\tREFUSED in res/", StringComparison.Ordinal), - "and writes the new one down after the old — later lines win"); + Expect(Occurrences(ledger, "verdict\t") == 1, "and writes no second verdict down"); + Expect(!Breadcrumbs.Trail.Contains("probe: open res/"), "having opened nothing"); } /// - /// A second launch replays what the first established instead of asking again. - /// The rungs that must not be repeated are the ones that can end a launch. + /// A second walk behind a verdict asks nothing at all. It used to replay the + /// answered rungs and re-make the repeatable ones, and on the AU7200 (issue + /// #105) the post-failure walk behind the early walk's verdict stopped on the + /// first of those — `probe: open res/`, on two builds — with the import census + /// queued behind it. The verdict is the answer; a walk cannot improve on it. /// private static void Resume(string root) { NativeProbe.Run(); + string verdict = NativeProbe.Summary; + Expect(verdict.Contains("maps executable and dlopen loaded it"), "the first walk reaches a verdict"); + NativeProbe.Run(); string trail = Breadcrumbs.Trail; - Expect(trail.Contains("res/:exec: answered on an earlier launch"), - "the second launch replays the executable mapping"); + Expect(trail.Contains("native probe: verdict already on the books — " + verdict + "; not walking again"), + "the second walk says the verdict is on the books"); + Expect(Occurrences(trail, "native probe: starting") == 2, + "and said it started before it looked — the ledger's own open is still a call"); + Expect(Occurrences(trail, "probe: open res/") == 1, + "and does not open the file again — nothing behind the verdict is worth a call"); Expect(Occurrences(trail, "probe: mmap PROT_READ|PROT_EXEC res/") == 1, - "and does not ask for it a second time"); - Expect(Occurrences(trail, "probe: open res/") == 2, - "but does open the file again — the rungs behind it need the descriptor"); + "nor ask for the executable mapping again"); + Expect(NativeProbe.Summary == verdict, "and the header still holds the verdict"); + Expect(NativeProbe.EngineFailedHere(), "a ledger with a verdict says the engine has failed here"); } /// @@ -251,6 +264,7 @@ private static void Abandoned(string root) /// private static void Early(string root, Stopwatch clock) { + Expect(NativeProbe.EngineFailedHere(), "an unfinished ledger says the engine has failed here"); bool started = NativeProbe.StartEarlyIfUnfinished(); Expect(started, "an unfinished ledger starts the walk ahead of the engine"); Expect(Breadcrumbs.Trail.Contains("walking it now, ahead of the engine"), @@ -266,6 +280,14 @@ private static void Early(string root, Stopwatch clock) Expect(NativeProbe.WaitForWalk(0), "a wait after the walk returns at once"); Expect(Occurrences(Breadcrumbs.Trail, "native probe: starting") == 1, "having started exactly once"); + + // The post-failure thread's walk, behind the early one, on the same launch: + // the shape that stopped the AU7200 twice. + NativeProbe.Run(); + Expect(Breadcrumbs.Trail.Contains("verdict already on the books"), + "a walk behind the early walk's verdict on the same launch asks nothing"); + Expect(Occurrences(Breadcrumbs.Trail, "probe: open res/") == 1, + "and the file is opened once in the launch"); } /// @@ -274,12 +296,22 @@ private static void Early(string root, Stopwatch clock) /// private static void NotEarly(string root) { + Expect(NativeProbe.Standing() == "no ledger", "no ledger: the standing says so"); + Expect(!NativeProbe.EngineFailedHere(), "no ledger: the engine has not failed here, nothing runs ahead of it"); Expect(!NativeProbe.StartEarlyIfUnfinished(), "no ledger: the engine goes first, as always"); File.WriteAllText(Path.Combine(root, "data", "probe-ledger.txt"), "ledger 3\nlaunch\nres/:exec\tPROT_READ|PROT_EXEC: ok\nverdict\tseeded\n"); + Expect(NativeProbe.Standing() == "finished", "a ledger with a verdict stands finished"); + Expect(NativeProbe.EngineFailedHere(), "and says the engine has failed here — the census still goes ahead of it"); Expect(!NativeProbe.StartEarlyIfUnfinished(), "a ledger with a verdict: nothing left to ask early"); Expect(!Breadcrumbs.Trail.Contains("native probe: starting"), "and neither started a walk"); + + NativeProbe.Run(); + Expect(Breadcrumbs.Trail.Contains("verdict already on the books — seeded; not walking again"), + "and the ordinary walk behind the engine takes the seeded verdict as the answer"); + Expect(!Breadcrumbs.Trail.Contains("probe: open res/"), "without opening a file"); + Expect(NativeProbe.Summary == "seeded", "the header shows it"); } ///