diff --git a/.github/workflows/ci.yaml b/.github/workflows/ci.yaml index 98cd3b0..aabf35d 100644 --- a/.github/workflows/ci.yaml +++ b/.github/workflows/ci.yaml @@ -149,30 +149,46 @@ jobs: } - name: Runtime smoke test (example app, real cef_host) # Runs the app against the cef_host it just built: first frame, eval, a - # JS channel, resize, freeze/thaw. Once as the runner composites, once - # with the GPU off (software paint). See - # example/lib/windows_smoke_probe.dart. + # JS channel, resize, freeze/thaw, and a crash loop on one of two tiles + # sharing a host. Once as the runner composites, once with the GPU off + # (software paint). The plugin's and hosts' log lines go to a file + # (FLUTTER_CEF_LOG_FILE); the crash-loop lines are printed, and the + # whole log when a mode fails. See example/lib/windows_smoke_probe.dart. shell: pwsh - timeout-minutes: 15 + timeout-minutes: 20 run: | cd example flutter build windows --debug -t lib/windows_smoke_probe.dart if ($LASTEXITCODE -ne 0) { exit $LASTEXITCODE } + $env:FLUTTER_CEF_SMOKE_CRASH_ROUNDS = "3" $failed = $false foreach ($mode in @("default", "software")) { if ($mode -eq "software") { $env:FLUTTER_CEF_SOFTWARE_COMPOSITING = "1" } $out = Join-Path $env:RUNNER_TEMP "windows_smoke_$mode.txt" + $log = Join-Path $env:RUNNER_TEMP "windows_smoke_$mode.log" $env:FLUTTER_CEF_PROBE_OUT = $out + $env:FLUTTER_CEF_LOG_FILE = $log $p = Start-Process -FilePath "build\windows\x64\runner\Debug\flutter_cef_example.exe" -PassThru - $timedOut = -not $p.WaitForExit(240000) + $timedOut = -not $p.WaitForExit(300000) if ($timedOut) { Stop-Process -Id $p.Id -Force -ErrorAction SilentlyContinue Get-Process cef_host -ErrorAction SilentlyContinue | Stop-Process -Force -ErrorAction SilentlyContinue } Write-Output "== smoke test, $mode compositing" if (Test-Path $out) { Get-Content $out } - if ($timedOut) { Write-Output "timed out after 240 s"; $failed = $true } - elseif (-not (Test-Path $out)) { Write-Output "no result file at $out"; $failed = $true } - elseif (-not (Select-String -Path $out -Pattern "CEF_PROBE_RESULT PASS" -Quiet)) { $failed = $true } + $modeFailed = $false + if ($timedOut) { Write-Output "timed out after 300 s"; $modeFailed = $true } + elseif (-not (Test-Path $out)) { Write-Output "no result file at $out"; $modeFailed = $true } + elseif (-not (Select-String -Path $out -Pattern "CEF_PROBE_RESULT PASS" -Quiet)) { $modeFailed = $true } + if (Test-Path $log) { + if ($modeFailed) { + Write-Output "== plugin and host log, $mode compositing" + Get-Content $log + } else { + Write-Output "== host crash-loop lines, $mode compositing" + Select-String -Path $log -Pattern "renderer terminated|giving up|several browsers|browser gone" | ForEach-Object { $_.Line } + } + } + if ($modeFailed) { $failed = $true } } if ($failed) { exit 1 } diff --git a/CHANGELOG.md b/CHANGELOG.md index e0f553c..a4b15f3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,11 @@ +## Unreleased + +* **Windows logs to a file on request**: set `FLUTTER_CEF_LOG_FILE` to a path + and the plugin appends its own and every `cef_host`'s log lines there (they + otherwise go only to `OutputDebugString`). +* The Windows runtime smoke test's crash-loop case no longer depends on the + network or a fixed pace, and CI prints the host's side of it. + ## 0.3.0 * **Windows catches up with macOS**: `sessionStats`, `setAudioMuted`, diff --git a/example/lib/windows_smoke_probe.dart b/example/lib/windows_smoke_probe.dart index c3f4474..42de905 100644 --- a/example/lib/windows_smoke_probe.dart +++ b/example/lib/windows_smoke_probe.dart @@ -47,7 +47,6 @@ const _html = ''' // isolation gives each its own renderer process and killing one can't take // the other with it. const _sentinelUrl = 'https://flutter-cef-sentinel.test/'; -const _victimUrl = 'https://flutter-cef-victim.test/'; void main() => runApp(const MaterialApp(home: ProbeApp())); @@ -209,33 +208,64 @@ class _ProbeAppState extends State { _check('probe ran to completion', false, '$e\n$st'); } await c.dispose(); - await _crashLoop(); + await _crashLoops(); _finish(); } + /// Polls [done] until it is true or [within] has passed. + Future _waitFor(bool Function() done, Duration within) async { + final sw = Stopwatch()..start(); + while (!done()) { + if (sw.elapsed >= within) return false; + await Future.delayed(const Duration(milliseconds: 20)); + } + return true; + } + /// A tile whose renderer keeps crashing ends alone; its neighbour on the - /// same host carries on. - Future _crashLoop() async { - const group = 'windows-smoke-crash-loop'; + /// same host carries on. FLUTTER_CEF_SMOKE_CRASH_ROUNDS runs it more than + /// once, each round on a fresh host. + Future _crashLoops() async { + final rounds = + int.tryParse( + Platform.environment['FLUTTER_CEF_SMOKE_CRASH_ROUNDS'] ?? '', + ) ?? + 1; + for (var round = 1; round <= rounds; round++) { + await _crashLoop(round); + } + } + + Future _crashLoop(int round) async { + final tag = 'crash loop $round'; + final group = 'windows-smoke-crash-loop-$round'; final sentinel = CefWebController(hostGroup: group); final victim = CefWebController(hostGroup: group); + // A timeline of the victim's side, printed with the result. + final clock = Stopwatch()..start(); + void event(String what) => + _log(' $tag +${clock.elapsedMilliseconds}ms $what'); String? sentinelGone; final victimGone = Completer(); - final sentinelLoaded = Completer(); - final victimLoaded = Completer(); + var sentinelLoaded = false; + var victimFinishes = 0; sentinel.onProcessGone = (r) => sentinelGone ??= r; + sentinel.onPageFinished = (_) => sentinelLoaded = true; victim.onProcessGone = (r) { + event('victim processGone($r)'); if (!victimGone.isCompleted) victimGone.complete(r); }; - sentinel.onPageFinished = (_) { - if (!sentinelLoaded.isCompleted) sentinelLoaded.complete(); - }; victim.onPageFinished = (_) { - if (!victimLoaded.isCompleted) victimLoaded.complete(); + victimFinishes++; + event('victim pageFinished'); }; - var victimLoads = 0; - victim.onPageStarted = (_) => victimLoads++; + victim.onLoadError = (e) => event('victim loadError ${e.errorText}'); try { + // The sentinel is served at an https origin and the victim is a data: + // page: different sites, so each gets its own renderer. A data: page + // also reloads without the network. (An authored victim loses its + // document at the first navigate, so its reloads went to DNS and came + // back as error pages, which report no pageStarted.) await sentinel.create( url: _sentinelUrl, html: _html, @@ -244,40 +274,49 @@ class _ProbeAppState extends State { height: 240, ); await victim.create( - url: _victimUrl, + url: 'about:blank', html: _html, - htmlBaseUrl: _victimUrl, width: 320, height: 240, ); - final loaded = - await Future.wait([sentinelLoaded.future, victimLoaded.future]) - .then((_) => true) - .timeout(const Duration(seconds: 60), onTimeout: () => false); - _check('crash loop: both tiles load', loaded); + _check( + '$tag: both tiles load', + await _waitFor( + () => sentinelLoaded && victimFinishes > 0, + const Duration(seconds: 60), + ), + ); // chrome://kill is a renderer debug URL: Chromium ends the tile's // renderer (exit code 1, no crash dump) and cef_host reloads the page. - // Four deaths within 10 s and the host gives up on the tile. - for (var i = 0; i < 8 && !victimGone.isCompleted; i++) { + // Each kill waits for that reload to finish, or for processGone, before + // the next, so every kill lands on a live, loaded page; one that shows + // neither within 5 s is sent again. Four deaths within 10 s and the host + // gives up on the tile. + var kills = 0; + while (!victimGone.isCompleted && + clock.elapsed < const Duration(seconds: 90)) { + final finishes = victimFinishes; + kills++; + event('kill $kills'); await victim.navigate('chrome://kill'); - await victimGone.future - .then((_) {}) - .timeout(const Duration(seconds: 1), onTimeout: () {}); + await _waitFor( + () => victimGone.isCompleted || victimFinishes > finishes, + const Duration(seconds: 5), + ); } - final gone = await victimGone.future.timeout( - const Duration(seconds: 15), - onTimeout: () => '', - ); + final gone = victimGone.isCompleted + ? await victimGone.future + : ''; _check( - 'crash loop: the crash-looping tile gets processGone(crashed)', + '$tag: the crash-looping tile gets processGone(crashed)', gone == 'crashed', gone, ); final before = await _presents(sentinel); _check( - 'crash loop: the other tile on the host keeps painting', + '$tag: the other tile on the host keeps painting', await _presentsPast( sentinel, before, @@ -288,14 +327,14 @@ class _ProbeAppState extends State { final four = await sentinel .runJavaScriptReturningResult('2 + 2') .timeout(const Duration(seconds: 10)); - _check('crash loop: the other tile answers evals', '$four' == '4', four); + _check('$tag: the other tile answers evals', '$four' == '4', four); _check( - 'crash loop: the other tile gets no processGone', + '$tag: the other tile gets no processGone', sentinelGone == null, sentinelGone, ); } catch (e, st) { - _check('crash loop case ran to completion', false, '$e\n$st'); + _check('$tag: ran to completion', false, '$e\n$st'); } await sentinel.dispose(); await victim.dispose(); diff --git a/packages/flutter_cef_windows/CHANGELOG.md b/packages/flutter_cef_windows/CHANGELOG.md index d8c7f32..6ffc035 100644 --- a/packages/flutter_cef_windows/CHANGELOG.md +++ b/packages/flutter_cef_windows/CHANGELOG.md @@ -1,3 +1,13 @@ +## Unreleased + +* `FLUTTER_CEF_LOG_FILE=` appends the plugin's and every `cef_host`'s log + lines to that file, each with a millisecond tick, as well as sending them to + `OutputDebugString`. +* CI: the smoke test's crash-loop case kills the tile's renderer only once the + previous reload has finished, re-sends a kill that didn't take, and uses a + `data:` page so a reload never goes to the network. It runs 3 rounds per + compositing mode and prints the host's crash-loop log lines. + ## 0.1.0 * Authored documents at a real origin (`kOpSetAuthoredHtml` 0x3f and the diff --git a/packages/flutter_cef_windows/README.md b/packages/flutter_cef_windows/README.md index b4f4dd4..90f9f67 100644 --- a/packages/flutter_cef_windows/README.md +++ b/packages/flutter_cef_windows/README.md @@ -68,6 +68,14 @@ rasterizer) when there is none. `