From e9b2f0ff8d62c54d6e1a1e7ee4c7c83ee509d5e8 Mon Sep 17 00:00:00 2001 From: Patrick Stel Date: Sat, 5 Sep 2026 17:13:35 +0200 Subject: [PATCH] Make the engine wait for a ladder that started ahead of it, and mark the hand-over to the main loop MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit build-1933ad8's two launches both went silent within a second of ENGINE FAILURE — the first on the ladder's first rung, the second, walking ahead of the engine, seven rungs in — with the probe thread, the permission probe's thread and the failure screen's heartbeat stopping together and the trail writer healthy at the last page load. Whatever ends these launches is timed off the engine's failure, not off any rung, and the early walk's head start was the half-second the engine took to fail. - On an install where the walk started ahead of the engine, OnCreate waits for it (NativeProbe.WaitForWalk, 90 s at most) before TryStartEngine, and says so. - Two trail markers around the hand-over: the last line OnCreate writes after the failure screen, and an EcoreMainloop.Post that writes when the loop first runs. - AppDomain.UnhandledException in Program.Main writes thread, type, message and stack before the abort; Main's catch only ever saw its own thread. Issue 17. docs/INTERNALS.md has the reading of the report. --- docs/INTERNALS.md | 72 ++++++++++++++++++++++++++++++++++-- src/common/NativeProbe.cs | 37 ++++++++++++++++++ src/elm/BrowserApp.cs | 42 ++++++++++++++++++++- src/elm/Program.cs | 22 +++++++++++ tools/probeladder/Program.cs | 12 +----- tools/probeladder/run.sh | 3 ++ 6 files changed, 174 insertions(+), 14 deletions(-) diff --git a/docs/INTERNALS.md b/docs/INTERNALS.md index e0480a8..6be4104 100644 --- a/docs/INTERNALS.md +++ b/docs/INTERNALS.md @@ -558,9 +558,12 @@ has a watchdog, a rung has to end two launches before it counts as a refusal, th trail can no longer hold the thread that writes to it and says in the header when it is stuck, the ladder walks ahead of the engine on an install whose disk already says the engine fails there, `tools/probeladder/run.sh` and `tools/trail/run.sh` hold all -of that off-device, and **`build-1933ad8` is the build that decides it** (shipped 2026-09-05). What each -answer means was said on the issue before it shipped, so neither reading is a -reversal later: +of that off-device, and the engine waits for the walk on an install where the walk +goes first — `build-1933ad8` answered seven rungs of `res/` in one launch that way +and lost the launch a second after the engine failed, see *Whatever ends the launch +is a second behind the engine* — and **`build-` is the build that decides +it**. What each answer means was said on the issue before it shipped, so neither +reading is a reversal later: - `own native : bin/ maps executable...` (or `lib/`, or `data/`) — there is a place in the package this set will run a file of ours from, and the stub is worth @@ -1007,6 +1010,69 @@ starts the walk ahead of the engine, and a second start is turned away) and meaning two launches ended on the same rung, which is a claim worth the weight the verdict puts on it. +### Whatever ends the launch is a second behind the engine, and does not care what the probe is doing + +`build-1933ad8` came back within the hour, three pages from two launches on a fresh +install. The first launch ran the ordinary order and ended, as before, on the ladder's +first rung. The second found the ledger, walked ahead of the engine, and answered +seven rungs — `control:anon-exec = ok` (the rung the launch before had "ended" on), +the copy into `data/`, the engine's header, and `res/`'s open, header, readable +mapping and `PROT_EXEC` (`EPERM`, the fourth time) — before ending on the +`/proc/self/fd` retry of that mapping, which is where `build-85d0e4e` ended too. The +permission probe ran beside it for the first time on this set and got as far as the +`getxattr` reads on `libmarlin.so.0`. + +Two things are settled by that page and one is not. + +- **The ladder converges now.** Two launches, seven answers, the abandoned rung asked + again and answered. The reporter's instruction is unchanged and finally true: open + it again until `own native :` stops saying `still asking`. +- **The writer was healthy.** `trail write: 29 lines on disk` on the page served from + inside the first launch, `3 lines on disk` at the start of each of the others. No + page was served *during* a silence, so the stall reading is not excluded — but it is + no longer the first reading. +- **What ends the launch is still unnamed, and it now has a shape.** Both launches went + silent within a second of `ENGINE FAILURE`: the first at `17:03:15` on the anon-exec + rung, the second at `17:04:43` on the `/proc/self/fd` retry, with the probe thread, + the permission probe's thread and the failure screen's heartbeat all stopping in the + same second and the deadline on the rung in flight never reporting. The early walk + bought the ladder exactly the half-second the engine took to fail. Whatever this is, + it is timed off the engine's failure or the failure screen behind it, not off any + rung, and three threads stopping together is a process ending, not a call parking. + The reporter has said as much since 2026-08-24 — "the logs lasts longer on the + screen … still not launching" — which is the on-screen log flashing and the app + closing. + +The two places on the main thread that can end a process a second after +`ENGINE FAILURE` are drawing the failure screen and handing control to the main loop, +where whatever `ewk_init` registered before it failed gets its first chance to run. +Nothing on the trail separates those, and a managed exception on any thread but the +main one — the probe's, the permission probe's, the writer's — ends the process with +no line at all, because `Program.Main`'s catch sees only its own thread. + +So `build-` does three things, all in `src/elm` and `Program.cs`: + +- **The engine waits for the walk.** On an install where the ladder started ahead of + the engine, `OnCreate` waits for it — `NativeProbe.WaitForWalk`, ninety seconds at + most — before `TryStartEngine`, and says so on the trail either way. If the killer + is timed off the engine's failure, the ladder gets the whole launch instead of a + rung or two; if it is timed off the process's start, nothing is lost that was not + lost already. Ninety seconds because a set that stalls every rung would otherwise + hold a black screen for four minutes; the ledger carries whatever is left. +- **Two markers around the hand-over.** `failure screen drawn — OnCreate returns, the + main loop starts` is the last line `OnCreate` writes, and an `EcoreMainloop.Post` + writes `main loop: first iteration ran` when the loop runs it. A trail that ends + between them ends in the main loop's first iteration, which is the engine's + registered callbacks; one that ends before the first ends in drawing the screen; one + that gets past both is something else. +- **An `UnhandledException` handler in `Main`** writes the thread's name, the type, + the message and the stack before the runtime aborts. `Drop` waits for the disk, so + the line lands. + +None of that is a fourth question for the reporter. The question is still the +ladder's, and the wait is what gives it the time to answer in one launch; the markers +and the handler are there so the *next* silence names its side of the hand-over. + ### `ELM_ACCEL` has to be set before the window exists `libchromium-ewk.so` has a library constructor whose entire body is diff --git a/src/common/NativeProbe.cs b/src/common/NativeProbe.cs index 341f85a..88302ea 100644 --- a/src/common/NativeProbe.cs +++ b/src/common/NativeProbe.cs @@ -856,6 +856,7 @@ public static void Run() return; } + Finished.Reset(); try { Walk(); @@ -863,12 +864,45 @@ public static void Run() finally { Interlocked.Exchange(ref _walking, 0); + Finished.Set(); } } /// 1 while a walk is in progress on some thread. private static int _walking; + /// Set whenever no walk is in progress; reset while one is. + private static readonly ManualResetEvent Finished = new ManualResetEvent(true); + + /// + /// Waits for a walk started by to finish, + /// for at most . True if it did. + /// + /// Both reports on `build-1933ad8` went silent within a second of + /// `ENGINE FAILURE` — the first at the ladder's first rung, the second, walking + /// ahead of the engine, seven rungs further on — with the probe thread, the + /// permission probe's thread and the failure screen's heartbeat all stopping + /// together and the trail writer healthy at the last page load. Whatever ends + /// those launches, it does so about a second in and does not care what the + /// probe is doing; the head start the early walk got was the half-second the + /// engine took to fail. So on an install where the ladder is walking ahead of + /// the engine, the engine waits for it. A set where the walk is what dies + /// loses nothing: the ledger has the rung. A set where the engine's failure — + /// or the main loop that follows it — is what dies gets the whole ladder in + /// one launch instead of a rung or two per launch. + /// + public static bool WaitForWalk(int timeoutMs) + { + try + { + return Finished.WaitOne(timeoutMs); + } + catch (Exception) + { + return false; + } + } + /// /// Walks the ladder now, on a thread of its own, if an earlier launch on this /// install got as far as starting it and it has not reached a verdict. @@ -929,6 +963,7 @@ public static void RunInBackground() return; } + Finished.Reset(); try { var thread = new Thread(delegate () @@ -940,6 +975,7 @@ public static void RunInBackground() finally { Interlocked.Exchange(ref _walking, 0); + Finished.Set(); } }); thread.IsBackground = true; @@ -957,6 +993,7 @@ public static void RunInBackground() finally { Interlocked.Exchange(ref _walking, 0); + Finished.Set(); } } } diff --git a/src/elm/BrowserApp.cs b/src/elm/BrowserApp.cs index f41de73..c6ee955 100644 --- a/src/elm/BrowserApp.cs +++ b/src/elm/BrowserApp.cs @@ -138,7 +138,26 @@ protected override void OnCreate() // install whose disk already says the engine fails here: see // NativeProbe.StartEarlyIfUnfinished for the reasoning. On every set // this app works on there is no ledger and this is a File.Exists. - NativeProbe.StartEarlyIfUnfinished(); + // + // And when it does start, the engine waits for it. build-1933ad8 walked + // ahead of the engine and still lost the launch a second after the + // engine failed, seven rungs in: whatever ends these launches is about a + // second behind ENGINE FAILURE and indifferent to the probe, so the only + // head start that counts is one where the engine is not asked until the + // 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. + if (NativeProbe.StartEarlyIfUnfinished()) + { + const int WalkBudgetMs = 90000; + Breadcrumbs.Drop("native probe: the engine waits for the walk (up to " + + (WalkBudgetMs / 1000) + " s)"); + var walkClock = System.Diagnostics.Stopwatch.StartNew(); + bool finished = NativeProbe.WaitForWalk(WalkBudgetMs); + Breadcrumbs.Drop(finished + ? "native probe: walk finished after " + walkClock.ElapsedMilliseconds + " ms — on to the engine" + : "native probe: still walking after " + (WalkBudgetMs / 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 @@ -165,6 +184,27 @@ protected override void OnCreate() if (!started) { ShowEngineFailure(); + + // The last two lines OnCreate can write, and the first the main + // loop does. Every launch on issue #17's set has gone silent within + // a second of ENGINE FAILURE, with the probe's thread, the permission + // probe's thread and the heartbeat all stopping together — which is + // the process ending, not a call stalling. The two places that can + // end it on the main thread are drawing this screen and handing + // control to the main loop, where whatever ewk_init registered + // before it failed gets its first chance to run. These lines say + // which side of that hand-over the launch was on. + Breadcrumbs.Drop("failure screen drawn — OnCreate returns, the main loop starts"); + try + { + EcoreMainloop.Post(delegate { Breadcrumbs.Drop("main loop: first iteration ran"); }); + } + catch (Exception ex) + { + Breadcrumbs.Drop("main loop: could not post the first-iteration marker (" + + ex.GetType().Name + ")"); + } + return; } diff --git a/src/elm/Program.cs b/src/elm/Program.cs index 7c5f665..213a203 100644 --- a/src/elm/Program.cs +++ b/src/elm/Program.cs @@ -23,6 +23,28 @@ private static void Main(string[] args) Breadcrumbs.Init(PackageId); Breadcrumbs.Drop("Main entered"); + // A managed exception on any thread but this one ends the process with + // no line anywhere: Main's catch below only sees the main thread. The + // probes run on threads of their own, and on issue #17's set every + // launch has ended within a second of the engine failing with three of + // those threads going quiet at once. If one of them threw, this is the + // only place that would ever say so. Drop waits for the disk, so the + // line is written before the runtime carries on with the abort. + try + { + AppDomain.CurrentDomain.UnhandledException += delegate (object sender, UnhandledExceptionEventArgs e) + { + Exception ex = e.ExceptionObject as Exception; + Breadcrumbs.Drop("FATAL on thread '" + (Thread.CurrentThread.Name ?? "?") + "': " + + (ex == null ? e.ExceptionObject.ToString() + : ex.GetType().Name + ": " + ex.Message + "\n" + ex.StackTrace)); + }; + } + catch (Exception) + { + // Nothing to do without it but carry on as before. + } + try { // Before Elementary, and therefore long before the window: the diff --git a/tools/probeladder/Program.cs b/tools/probeladder/Program.cs index 89d91f9..356e69b 100644 --- a/tools/probeladder/Program.cs +++ b/tools/probeladder/Program.cs @@ -260,18 +260,10 @@ private static void Early(string root, Stopwatch clock) Expect(Breadcrumbs.Trail.Contains("native probe: already walking on another thread"), "the ordinary start behind it is turned away rather than run twice"); - while (NativeProbe.Summary.StartsWith("still asking") || NativeProbe.Summary.StartsWith("(not asked")) - { - if (clock.ElapsedMilliseconds > 60000) - { - break; - } - - System.Threading.Thread.Sleep(50); - } - + Expect(NativeProbe.WaitForWalk(60000), "the engine can wait for the walk, and it finishes"); Expect(NativeProbe.Summary.Contains("maps executable and dlopen loaded it"), "and the early walk reaches this box's verdict (" + NativeProbe.Summary + ")"); + Expect(NativeProbe.WaitForWalk(0), "a wait after the walk returns at once"); Expect(Occurrences(Breadcrumbs.Trail, "native probe: starting") == 1, "having started exactly once"); } diff --git a/tools/probeladder/run.sh b/tools/probeladder/run.sh index 47578ef..81bc48e 100755 --- a/tools/probeladder/run.sh +++ b/tools/probeladder/run.sh @@ -25,6 +25,9 @@ # the anonymous-exec control, a rung the set had answered `ok` three # times before. One ended launch is not a refusal, and a ladder that # is only reached one launch in three is not a ladder. +# build-1933ad8 walked ahead of the engine and answered seven rungs in one launch, +# then lost the launch a second after the engine failed, like every +# launch before it. The engine waits for the walk now. # # Each round trip is somebody's evening: install, re-sign, launch, copy a page out # of a TV browser. That is far too expensive a way to find out that a ladder does