Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
49 changes: 27 additions & 22 deletions cmd/dumber/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ import (
"runtime"
"strings"
"syscall"
"time"

"github.com/bnema/dumber/internal/application/port"
"github.com/bnema/dumber/internal/application/usecase"
Expand Down Expand Up @@ -140,11 +141,16 @@ func configureBrowserLaunchRelay(cfg *config.Config) {
browserLaunchRelay = relay
}

type startupTiming struct {
processEntry time.Time
configComplete time.Time
}

func main() {
// This is intentionally before subprocess detection: each process records
// its own first observable main event before CEF can take over execution.
logging.InitStartupTrace("")
logging.Trace().Mark("process_entry")
// CEF is not known until configuration is complete. Keep these neutral
// timestamps so a CEF GUI trace can be seeded truthfully without creating
// one for WebKit, the standalone omnibox, CLI, or CEF helper processes.
timing := startupTiming{processEntry: time.Now()}

// CEF subprocess handling: when CEF re-launches this binary with
// --type=renderer/gpu/etc, we must call ExecuteProcess before anything
Expand Down Expand Up @@ -175,6 +181,7 @@ func main() {
// Run GUI mode for browse command
if mode == launchModeBrowse {
cfg := initConfig()
timing.configComplete = time.Now()
configureBrowserLaunchRelay(cfg)
startupURL := domainurl.ResolveBrowserStartupURL(browseURL)
if forwarded, err := tryForwardBrowseURLToRunningInstance(context.Background(), browserLaunchRelay, startupURL); err != nil {
Expand All @@ -191,7 +198,7 @@ func main() {
initialURL = startupURL
restoreSessionID = os.Getenv("DUMBER_RESTORE_SESSION")
os.Args = os.Args[:1]
os.Exit(runGUI(cfg))
os.Exit(runGUI(cfg, timing))
return
}

Expand All @@ -212,7 +219,7 @@ func main() {
cmd.Execute()
}

func runGUI(cfg *config.Config) int {
func runGUI(cfg *config.Config, timing startupTiming) int {
bootstrap.ApplyGTKIMModuleFallbackDefault(os.Stderr)

runtime.LockOSThread()
Expand All @@ -221,12 +228,13 @@ func runGUI(cfg *config.Config) int {

if cfg == nil {
cfg = initConfig()
timing.configComplete = time.Now()
configureBrowserLaunchRelay(cfg)
}
logging.Trace().Mark("config_complete")
timer.Mark("config")

ctx := initStartupContextWithTrace(cfg)
ctx := initStartupContext(cfg)
activateCEFStartupTraceForGUI(cfg, timing, logging.FromContext(ctx), infracef.ActivateStartupTrace)
applyCEFRenderStackDefault(ctx, cfg)
timer.Mark("logger")
bootstrapLog := logging.FromContext(ctx)
Expand Down Expand Up @@ -259,7 +267,6 @@ func runGUI(cfg *config.Config) int {
timer.Mark("session")

log := logging.FromContext(ctx)
logging.Trace().UpdateLogger(log)
logCoreDumpLimits(ctx)

engine.SetHandlerContext(ctx)
Expand Down Expand Up @@ -303,7 +310,7 @@ func runStandaloneOmnibox() int {

cfg := initConfig()
configureBrowserLaunchRelay(cfg)
ctx := initStartupContextWithTrace(cfg)
ctx := initStartupContext(cfg)
applyCEFRenderStackDefault(ctx, cfg)

initResult, err := runParallelInitPhase(ctx, cfg)
Expand Down Expand Up @@ -418,20 +425,19 @@ func resolveCurrentExecutable(executable func() (string, error)) (string, error)
return executable()
}

func initStartupContextWithTrace(cfg *config.Config) context.Context {
logging.InitStartupTrace(cfg.Logging.Level)

ctx := initStartupContext(cfg)
bootstrapLog := logging.FromContext(ctx)

logging.Trace().SetLogger(bootstrapLog)
logging.Trace().Mark("logger_init")

return ctx
func activateCEFStartupTraceForGUI(
cfg *config.Config,
timing startupTiming,
logger *zerolog.Logger,
activate func(time.Time, time.Time, *zerolog.Logger),
) {
if cfg == nil || cfg.Engine.ResolveEngineType() != config.EngineTypeCEF {
return
}
activate(timing.processEntry, timing.configComplete, logger)
}

func runParallelInitPhase(ctx context.Context, cfg *config.Config) (*bootstrap.ParallelInitResult, error) {
logging.Trace().Mark("parallel_start")
initResult, err := bootstrap.RunParallelInit(bootstrap.ParallelInitInput{
Ctx: ctx,
Config: cfg,
Expand All @@ -440,7 +446,6 @@ func runParallelInitPhase(ctx context.Context, cfg *config.Config) (*bootstrap.P
handleParallelInitError(ctx, err)
return nil, err
}
logging.Trace().Mark("parallel_done")
return initResult, nil
}

Expand Down
16 changes: 16 additions & 0 deletions cmd/dumber/main_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -4,12 +4,14 @@ import (
"context"
"errors"
"testing"
"time"

"github.com/bnema/dumber/internal/application/port/mocks"
"github.com/bnema/dumber/internal/bootstrap"
"github.com/bnema/dumber/internal/infrastructure/colorscheme"
"github.com/bnema/dumber/internal/infrastructure/config"
"github.com/bnema/dumber/internal/infrastructure/desktop"
"github.com/rs/zerolog"
)

func TestLaunchModeFromArgs_DetectsStandaloneOmnibox(t *testing.T) {
Expand Down Expand Up @@ -172,6 +174,20 @@ func TestResolveCurrentExecutable_PropagatesError(t *testing.T) {
}
}

func TestWebKitGUIStartupDoesNotActivateCEFTrace(t *testing.T) {
cfg := &config.Config{}
cfg.Engine.Type = config.EngineTypeWebKit
activationCalls := 0

activateCEFStartupTraceForGUI(cfg, startupTiming{}, nil, func(time.Time, time.Time, *zerolog.Logger) {
activationCalls++
})

if activationCalls != 0 {
t.Fatal("WebKit GUI startup must not initialize, record, or summarize the CEF first-presentation trace")
}
}

func TestPreInitializeAdwaitaForCEF_InitializesAndMarksDetector(t *testing.T) {
initResult := &bootstrap.ParallelInitResult{
AdwaitaDetector: colorscheme.NewAdwaitaDetector(),
Expand Down
30 changes: 23 additions & 7 deletions docs/first-presentation.md
Original file line number Diff line number Diff line change
@@ -1,7 +1,14 @@
# First presentation startup trace
# CEF accelerated first-presentation startup trace

Dumber records one cold-start timeline for each GUI process. The trace begins
at `process_entry`, before CEF subprocess handling, and accepts these one-shot
Dumber records this cold-start timeline **only for the accelerated CEF → DMABUF
→ GTK path**. It is not a backend-neutral startup metric: the WebKit backend
does not add milestones to this trace and never emits this CEF summary.

For a selected CEF GUI process, Dumber captures neutral `process_entry` and
`config_complete` timestamps, then activates and seeds this CEF-owned trace only
after configuration selects CEF. CEF helper processes, WebKit GUI startup, the
standalone omnibox, and CLI commands never initialize this trace, record its
milestones, or emit its summary. A selected CEF GUI trace accepts these one-shot
milestones only in order:

1. `process_entry`
Expand All @@ -13,11 +20,19 @@ milestones only in order:
7. `first_dmabuf_texture_swap` (after `GtkPicture.SetPaintable` succeeds)
8. `first_gtk_presentation` (the subsequent GTK frame-clock after-paint)

CEF library-load completion is intentionally not recorded: `InitWithApp` is an
The CEF-to-GTK bridge owns the native accelerated-paint, DMABUF texture-swap,
and GTK presentation boundaries. Dumber records the bridge's ordered callbacks;
it does not synthesize them for another engine or rendering path. CEF
library-load completion is intentionally not recorded: `InitWithApp` is an
opaque operation. Duplicate, unknown, and out-of-order transitions are
rejected. At the last milestone Dumber emits exactly one normal-level JSON
summary (`startup_trace: first presentation`) with the selected `backend`, an
`incomplete_reason`, total milliseconds, and monotonic milestones.
summary (`startup_trace: first presentation`) with the selected CEF render
backend, an `incomplete_reason`, total milliseconds, and monotonic milestones.

A non-DMABUF CEF backend or a missing accelerated callback does not produce a
complete summary and is not comparable with this measurement. In particular,
WebKit startup must be measured with a separately defined WebKit-specific
contract rather than this CEF trace.

## Reproducible collection

Expand All @@ -29,7 +44,8 @@ DUMBER_MACHINE_GPU_PROFILE=integrated-gpu \
scripts/collect_first_presentation.sh
```

By default each collection is a fresh directory below
The collector is for the accelerated CEF/DMABUF/GTK contract above. By default
each collection is a fresh directory below
`$XDG_STATE_HOME/dumber/roadmap-evidence` (or
`$HOME/.local/state/dumber/roadmap-evidence` when `XDG_STATE_HOME` is unset),
not in the repository. `DUMBER_FIRST_PRESENTATION_OUTPUT` may override it only
Expand Down
6 changes: 3 additions & 3 deletions internal/infrastructure/cef/engine_init.go
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ func NewEngine(
return nil, err
}
cef2gtk.ConfigureRenderStackEnvironment(renderStackPlan)
logging.Trace().SetBackend(renderStackPlan.Backend.String())
activeStartupTrace().SetBackend(renderStackPlan.Backend.String())

settings, err := prepareCEFSettings(opts, paths, cfg, logger)
if err != nil {
Expand Down Expand Up @@ -218,11 +218,11 @@ func initializeCEF(eng *Engine, settings purecef.Settings, logger *zerolog.Logge
logger.Debug().Msg("cef: calling InitWithApp")
// InitWithApp encapsulates loading libcef, so only the begin boundary is
// observable here; do not invent a separate library-load completion event.
logging.Trace().Mark("cef_library_load_begin")
activeStartupTrace().Mark("cef_library_load_begin")
if err := purecef.InitWithApp(settings, app); err != nil {
return fmt.Errorf("cef.InitWithApp: %w", err)
}
logging.Trace().Mark("cef_initialized")
activeStartupTrace().Mark("cef_initialized")
if libcefPath := loadedLibCEFPath(); libcefPath != "" {
logger.Info().Str("libcef_path", libcefPath).Msg("cef: runtime library loaded")
} else {
Expand Down
2 changes: 1 addition & 1 deletion internal/infrastructure/cef/factory.go
Original file line number Diff line number Diff line change
Expand Up @@ -279,7 +279,7 @@ func (f *WebViewFactory) postPendingBrowserCreate(ctx context.Context, wv *WebVi
// OnAfterCreated once the host is fully wired.
initialURL := "about:blank"
// This is the request boundary, not the later OnAfterCreated callback.
logging.Trace().Mark("browser_create_requested")
activeStartupTrace().Mark("browser_create_requested")
result := cefBrowserHostCreateBrowser(
pc.windowInfo,
pc.client,
Expand Down
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
package logging
package cef

import (
"encoding/json"
Expand All @@ -23,7 +23,7 @@ const validFirstPresentationLog = `{"message":"startup_trace: milestone","milest
{"message":"startup_trace: first presentation","backend":"gdk-dmabuf","incomplete_reason":"","total_ms":7,"host":"alice"}`

func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)
script, err := os.ReadFile(filepath.Join(repoRoot, "scripts", "collect_first_presentation.sh"))
require.NoError(t, err)
Expand All @@ -32,7 +32,7 @@ func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testin
}

func TestFirstPresentationCollectorRejectsUnsafeOutputPaths(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)
temp := t.TempDir()
runtime := filepath.Join(temp, "cef-147-runtime")
Expand Down Expand Up @@ -109,7 +109,7 @@ func requireFileContents(t *testing.T, path, want string) {
}

func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)
temp := t.TempDir()
runtime := filepath.Join(temp, "cef-147-runtime")
Expand Down Expand Up @@ -169,7 +169,7 @@ func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {
}

func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)
temp := t.TempDir()
runtime := filepath.Join(temp, "cef-147-runtime")
Expand Down Expand Up @@ -218,7 +218,7 @@ func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *t
}

func TestFirstPresentationCollectorRejectsNonImmutableModuleProvenanceWithoutLeaks(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)

for _, test := range []struct {
Expand Down Expand Up @@ -298,7 +298,7 @@ exit 1
}

func TestFirstPresentationCollectorDefaultsToXDGStateEvidenceDirectory(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)
temp := t.TempDir()
runtime := filepath.Join(temp, "cef-147-runtime")
Expand Down Expand Up @@ -342,7 +342,7 @@ func envWithout(name string) []string {
}

func TestFirstPresentationCollectorReadsProvenanceWithScopedGitSafeDirectory(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)
temp := t.TempDir()
runtime := filepath.Join(temp, "cef-147-runtime")
Expand Down Expand Up @@ -386,7 +386,7 @@ exit 128
}

func TestFirstPresentationCollectorRejectsInconsistentTiming(t *testing.T) {
repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
require.NoError(t, err)

for _, test := range []struct {
Expand Down
12 changes: 6 additions & 6 deletions internal/infrastructure/cef/render_handler_adapter.go
Original file line number Diff line number Diff line change
Expand Up @@ -26,19 +26,19 @@ var _ purecef.RenderHandler = (*dumberRenderHandler)(nil)
// startupPresentationHooks consumes the one-shot facts emitted by
// purego-cef2gtk. The bridge owns the native DMABUF and frame-clock boundaries;
// Dumber only records their ordered application-level timeline.
func startupPresentationHooks() cef2gtk.Hooks {
func startupPresentationHooks(trace *startupTrace) cef2gtk.Hooks {
return cef2gtk.Hooks{
OnFirstAcceleratedPaint: func() {
logging.Trace().Mark("first_accelerated_paint_received")
trace.Mark("first_accelerated_paint_received")
},
OnFirstDMABUFTextureSwap: func() {
logging.Trace().Mark("first_dmabuf_texture_swap")
trace.Mark("first_dmabuf_texture_swap")
},
OnFirstPresentation: func() {
logging.Trace().MarkGTKAfterPaint()
trace.MarkGTKAfterPaint()
},
OnDMABUFUnsupported: func() {
logging.Trace().SetIncompleteReason("dmabuf_texture_swap_unavailable")
trace.SetIncompleteReason("dmabuf_texture_swap_unavailable")
},
}
}
Expand All @@ -50,7 +50,7 @@ func newDumberRenderHandler(wv *WebView) purecef.RenderHandler {
h := &dumberRenderHandler{wv: wv}

var unsupportedPaintOnce sync.Once
hooks := startupPresentationHooks()
hooks := startupPresentationHooks(activeStartupTrace())
hooks.OnUnsupportedPaint = func() {
unsupportedPaintOnce.Do(func() {
if wv.ctx != nil {
Expand Down
Loading