Merge pull request #354 from bnema/fix/startup-trace-contract

fix(startup): scope trace to accelerated CEF

commit: c811fd01b598658155acfdb6b2a7a19fc52a81d5
author: bnema · 3mo ago · 2026-07-15 08:57 UTC
committer: GitHub · 3mo ago · 2026-07-15 08:57 UTC
merge of: 80795e3 + 6949e93 · diff against the first parent
signature: GPG UnverifiedB5690EEEBB952194 The key is unknown

16 files · +392 -301

M cmd/dumber/main.go +27 -22


@@ -10,6 +10,7 @@ import (
10	10		"runtime"
11	11		"strings"
12	12		"syscall"
	13	+	"time"
13	14
14	15		"github.com/bnema/dumber/internal/application/port"
15	16		"github.com/bnema/dumber/internal/application/usecase"

@@ -140,11 +141,16 @@ func configureBrowserLaunchRelay(cfg *config.Config) {
140	141		browserLaunchRelay = relay
141	142		}
142	143
	144	+	type startupTiming struct {
	145	+	processEntry time.Time
	146	+	configComplete time.Time
	147	+	}
	148	+
143	149		func main() {
144		-	// This is intentionally before subprocess detection: each process records
145		-	// its own first observable main event before CEF can take over execution.
146		-	logging.InitStartupTrace("")
147		-	logging.Trace().Mark("process_entry")
	150	+	// CEF is not known until configuration is complete. Keep these neutral
	151	+	// timestamps so a CEF GUI trace can be seeded truthfully without creating
	152	+	// one for WebKit, the standalone omnibox, CLI, or CEF helper processes.
	153	+	timing := startupTiming{processEntry: time.Now()}
148	154
149	155		// CEF subprocess handling: when CEF re-launches this binary with
150	156		// --type=renderer/gpu/etc, we must call ExecuteProcess before anything

@@ -175,6 +181,7 @@ func main() {
175	181		// Run GUI mode for browse command
176	182		if mode == launchModeBrowse {
177	183		cfg := initConfig()
	184	+	timing.configComplete = time.Now()
178	185		configureBrowserLaunchRelay(cfg)
179	186		startupURL := domainurl.ResolveBrowserStartupURL(browseURL)
180	187		if forwarded, err := tryForwardBrowseURLToRunningInstance(context.Background(), browserLaunchRelay, startupURL); err != nil {

@@ -191,7 +198,7 @@ func main() {
191	198		initialURL = startupURL
192	199		restoreSessionID = os.Getenv("DUMBER_RESTORE_SESSION")
193	200		os.Args = os.Args[:1]
194		-	os.Exit(runGUI(cfg))
	201	+	os.Exit(runGUI(cfg, timing))
195	202		return
196	203		}
197	204

@@ -212,7 +219,7 @@ func main() {
212	219		cmd.Execute()
213	220		}
214	221
215		-	func runGUI(cfg *config.Config) int {
	222	+	func runGUI(cfg *config.Config, timing startupTiming) int {
216	223		bootstrap.ApplyGTKIMModuleFallbackDefault(os.Stderr)
217	224
218	225		runtime.LockOSThread()

@@ -221,12 +228,13 @@ func runGUI(cfg *config.Config) int {
221	228
222	229		if cfg == nil {
223	230		cfg = initConfig()
	231	+	timing.configComplete = time.Now()
224	232		configureBrowserLaunchRelay(cfg)
225	233		}
226		-	logging.Trace().Mark("config_complete")
227	234		timer.Mark("config")
228	235
229		-	ctx := initStartupContextWithTrace(cfg)
	236	+	ctx := initStartupContext(cfg)
	237	+	activateCEFStartupTraceForGUI(cfg, timing, logging.FromContext(ctx), infracef.ActivateStartupTrace)
230	238		applyCEFRenderStackDefault(ctx, cfg)
231	239		timer.Mark("logger")
232	240		bootstrapLog := logging.FromContext(ctx)

@@ -259,7 +267,6 @@ func runGUI(cfg *config.Config) int {
259	267		timer.Mark("session")
260	268
261	269		log := logging.FromContext(ctx)
262		-	logging.Trace().UpdateLogger(log)
263	270		logCoreDumpLimits(ctx)
264	271
265	272		engine.SetHandlerContext(ctx)

@@ -303,7 +310,7 @@ func runStandaloneOmnibox() int {
303	310
304	311		cfg := initConfig()
305	312		configureBrowserLaunchRelay(cfg)
306		-	ctx := initStartupContextWithTrace(cfg)
	313	+	ctx := initStartupContext(cfg)
307	314		applyCEFRenderStackDefault(ctx, cfg)
308	315
309	316		initResult, err := runParallelInitPhase(ctx, cfg)

@@ -418,20 +425,19 @@ func resolveCurrentExecutable(executable func() (string, error)) (string, error)
418	425		return executable()
419	426		}
420	427
421		-	func initStartupContextWithTrace(cfg *config.Config) context.Context {
422		-	logging.InitStartupTrace(cfg.Logging.Level)
423		-
424		-	ctx := initStartupContext(cfg)
425		-	bootstrapLog := logging.FromContext(ctx)
426		-
427		-	logging.Trace().SetLogger(bootstrapLog)
428		-	logging.Trace().Mark("logger_init")
429		-
430		-	return ctx
	428	+	func activateCEFStartupTraceForGUI(
	429	+	cfg *config.Config,
	430	+	timing startupTiming,
	431	+	logger *zerolog.Logger,
	432	+	activate func(time.Time, time.Time, *zerolog.Logger),
	433	+	) {
	434	+	if cfg == nil \|\| cfg.Engine.ResolveEngineType() != config.EngineTypeCEF {
	435	+	return
	436	+	}
	437	+	activate(timing.processEntry, timing.configComplete, logger)
431	438		}
432	439
433	440		func runParallelInitPhase(ctx context.Context, cfg config.Config) (bootstrap.ParallelInitResult, error) {
434		-	logging.Trace().Mark("parallel_start")
435	441		initResult, err := bootstrap.RunParallelInit(bootstrap.ParallelInitInput{
436	442		Ctx: ctx,
437	443		Config: cfg,

@@ -440,7 +446,6 @@ func runParallelInitPhase(ctx context.Context, cfg config.Config) (bootstrap.P
440	446		handleParallelInitError(ctx, err)
441	447		return nil, err
442	448		}
443		-	logging.Trace().Mark("parallel_done")
444	449		return initResult, nil
445	450		}
446	451


@@ -10,6 +10,7 @@ import (
10		"runtime"	10		"runtime"
11		"strings"	11		"strings"
12		"syscall"	12		"syscall"
			13	+	"time"
13			14
14		"github.com/bnema/dumber/internal/application/port"	15		"github.com/bnema/dumber/internal/application/port"
15		"github.com/bnema/dumber/internal/application/usecase"	16		"github.com/bnema/dumber/internal/application/usecase"

@@ -140,11 +141,16 @@ func configureBrowserLaunchRelay(cfg *config.Config) {
140		browserLaunchRelay = relay	141		browserLaunchRelay = relay
141		}	142		}
142			143
			144	+	type startupTiming struct {
			145	+	processEntry time.Time
			146	+	configComplete time.Time
			147	+	}
			148	+
143		func main() {	149		func main() {
144	-	// This is intentionally before subprocess detection: each process records	150	+	// CEF is not known until configuration is complete. Keep these neutral
145	-	// its own first observable main event before CEF can take over execution.	151	+	// timestamps so a CEF GUI trace can be seeded truthfully without creating
146	-	logging.InitStartupTrace("")	152	+	// one for WebKit, the standalone omnibox, CLI, or CEF helper processes.
147	-	logging.Trace().Mark("process_entry")	153	+	timing := startupTiming{processEntry: time.Now()}
148			154
149		// CEF subprocess handling: when CEF re-launches this binary with	155		// CEF subprocess handling: when CEF re-launches this binary with
150		// --type=renderer/gpu/etc, we must call ExecuteProcess before anything	156		// --type=renderer/gpu/etc, we must call ExecuteProcess before anything

@@ -175,6 +181,7 @@ func main() {
175		// Run GUI mode for browse command	181		// Run GUI mode for browse command
176		if mode == launchModeBrowse {	182		if mode == launchModeBrowse {
177		cfg := initConfig()	183		cfg := initConfig()
			184	+	timing.configComplete = time.Now()
178		configureBrowserLaunchRelay(cfg)	185		configureBrowserLaunchRelay(cfg)
179		startupURL := domainurl.ResolveBrowserStartupURL(browseURL)	186		startupURL := domainurl.ResolveBrowserStartupURL(browseURL)
180		if forwarded, err := tryForwardBrowseURLToRunningInstance(context.Background(), browserLaunchRelay, startupURL); err != nil {	187		if forwarded, err := tryForwardBrowseURLToRunningInstance(context.Background(), browserLaunchRelay, startupURL); err != nil {

@@ -191,7 +198,7 @@ func main() {
191		initialURL = startupURL	198		initialURL = startupURL
192		restoreSessionID = os.Getenv("DUMBER_RESTORE_SESSION")	199		restoreSessionID = os.Getenv("DUMBER_RESTORE_SESSION")
193		os.Args = os.Args[:1]	200		os.Args = os.Args[:1]
194	-	os.Exit(runGUI(cfg))	201	+	os.Exit(runGUI(cfg, timing))
195		return	202		return
196		}	203		}
197			204

@@ -212,7 +219,7 @@ func main() {
212		cmd.Execute()	219		cmd.Execute()
213		}	220		}
214			221
215	-	func runGUI(cfg *config.Config) int {	222	+	func runGUI(cfg *config.Config, timing startupTiming) int {
216		bootstrap.ApplyGTKIMModuleFallbackDefault(os.Stderr)	223		bootstrap.ApplyGTKIMModuleFallbackDefault(os.Stderr)
217			224
218		runtime.LockOSThread()	225		runtime.LockOSThread()

@@ -221,12 +228,13 @@ func runGUI(cfg *config.Config) int {
221			228
222		if cfg == nil {	229		if cfg == nil {
223		cfg = initConfig()	230		cfg = initConfig()
			231	+	timing.configComplete = time.Now()
224		configureBrowserLaunchRelay(cfg)	232		configureBrowserLaunchRelay(cfg)
225		}	233		}
226	-	logging.Trace().Mark("config_complete")
227		timer.Mark("config")	234		timer.Mark("config")
228			235
229	-	ctx := initStartupContextWithTrace(cfg)	236	+	ctx := initStartupContext(cfg)
			237	+	activateCEFStartupTraceForGUI(cfg, timing, logging.FromContext(ctx), infracef.ActivateStartupTrace)
230		applyCEFRenderStackDefault(ctx, cfg)	238		applyCEFRenderStackDefault(ctx, cfg)
231		timer.Mark("logger")	239		timer.Mark("logger")
232		bootstrapLog := logging.FromContext(ctx)	240		bootstrapLog := logging.FromContext(ctx)

@@ -259,7 +267,6 @@ func runGUI(cfg *config.Config) int {
259		timer.Mark("session")	267		timer.Mark("session")
260			268
261		log := logging.FromContext(ctx)	269		log := logging.FromContext(ctx)
262	-	logging.Trace().UpdateLogger(log)
263		logCoreDumpLimits(ctx)	270		logCoreDumpLimits(ctx)
264			271
265		engine.SetHandlerContext(ctx)	272		engine.SetHandlerContext(ctx)

@@ -303,7 +310,7 @@ func runStandaloneOmnibox() int {
303			310
304		cfg := initConfig()	311		cfg := initConfig()
305		configureBrowserLaunchRelay(cfg)	312		configureBrowserLaunchRelay(cfg)
306	-	ctx := initStartupContextWithTrace(cfg)	313	+	ctx := initStartupContext(cfg)
307		applyCEFRenderStackDefault(ctx, cfg)	314		applyCEFRenderStackDefault(ctx, cfg)
308			315
309		initResult, err := runParallelInitPhase(ctx, cfg)	316		initResult, err := runParallelInitPhase(ctx, cfg)

@@ -418,20 +425,19 @@ func resolveCurrentExecutable(executable func() (string, error)) (string, error)
418		return executable()	425		return executable()
419		}	426		}
420			427
421	-	func initStartupContextWithTrace(cfg *config.Config) context.Context {	428	+	func activateCEFStartupTraceForGUI(
422	-	logging.InitStartupTrace(cfg.Logging.Level)	429	+	cfg *config.Config,
423	-		430	+	timing startupTiming,
424	-	ctx := initStartupContext(cfg)	431	+	logger *zerolog.Logger,
425	-	bootstrapLog := logging.FromContext(ctx)	432	+	activate func(time.Time, time.Time, *zerolog.Logger),
426	-		433	+	) {
427	-	logging.Trace().SetLogger(bootstrapLog)	434	+	if cfg == nil \|\| cfg.Engine.ResolveEngineType() != config.EngineTypeCEF {
428	-	logging.Trace().Mark("logger_init")	435	+	return
429	-		436	+	}
430	-	return ctx	437	+	activate(timing.processEntry, timing.configComplete, logger)
431		}	438		}
432			439
433		func runParallelInitPhase(ctx context.Context, cfg config.Config) (bootstrap.ParallelInitResult, error) {	440		func runParallelInitPhase(ctx context.Context, cfg config.Config) (bootstrap.ParallelInitResult, error) {
434	-	logging.Trace().Mark("parallel_start")
435		initResult, err := bootstrap.RunParallelInit(bootstrap.ParallelInitInput{	441		initResult, err := bootstrap.RunParallelInit(bootstrap.ParallelInitInput{
436		Ctx: ctx,	442		Ctx: ctx,
437		Config: cfg,	443		Config: cfg,

@@ -440,7 +446,6 @@ func runParallelInitPhase(ctx context.Context, cfg config.Config) (bootstrap.P
440		handleParallelInitError(ctx, err)	446		handleParallelInitError(ctx, err)
441		return nil, err	447		return nil, err
442		}	448		}
443	-	logging.Trace().Mark("parallel_done")
444		return initResult, nil	449		return initResult, nil
445		}	450		}
446			451

M cmd/dumber/main_test.go +16 -0


@@ -4,12 +4,14 @@ import (
4	4		"context"
5	5		"errors"
6	6		"testing"
	7	+	"time"
7	8
8	9		"github.com/bnema/dumber/internal/application/port/mocks"
9	10		"github.com/bnema/dumber/internal/bootstrap"
10	11		"github.com/bnema/dumber/internal/infrastructure/colorscheme"
11	12		"github.com/bnema/dumber/internal/infrastructure/config"
12	13		"github.com/bnema/dumber/internal/infrastructure/desktop"
	14	+	"github.com/rs/zerolog"
13	15		)
14	16
15	17		func TestLaunchModeFromArgs_DetectsStandaloneOmnibox(t *testing.T) {

@@ -172,6 +174,20 @@ func TestResolveCurrentExecutable_PropagatesError(t *testing.T) {
172	174		}
173	175		}
174	176
	177	+	func TestWebKitGUIStartupDoesNotActivateCEFTrace(t *testing.T) {
	178	+	cfg := &config.Config{}
	179	+	cfg.Engine.Type = config.EngineTypeWebKit
	180	+	activationCalls := 0
	181	+
	182	+	activateCEFStartupTraceForGUI(cfg, startupTiming{}, nil, func(time.Time, time.Time, *zerolog.Logger) {
	183	+	activationCalls++
	184	+	})
	185	+
	186	+	if activationCalls != 0 {
	187	+	t.Fatal("WebKit GUI startup must not initialize, record, or summarize the CEF first-presentation trace")
	188	+	}
	189	+	}
	190	+
175	191		func TestPreInitializeAdwaitaForCEF_InitializesAndMarksDetector(t *testing.T) {
176	192		initResult := &bootstrap.ParallelInitResult{
177	193		AdwaitaDetector: colorscheme.NewAdwaitaDetector(),


@@ -4,12 +4,14 @@ import (
4	"context"	4		"context"
5	"errors"	5		"errors"
6	"testing"	6		"testing"
		7	+	"time"
7		8
8	"github.com/bnema/dumber/internal/application/port/mocks"	9		"github.com/bnema/dumber/internal/application/port/mocks"
9	"github.com/bnema/dumber/internal/bootstrap"	10		"github.com/bnema/dumber/internal/bootstrap"
10	"github.com/bnema/dumber/internal/infrastructure/colorscheme"	11		"github.com/bnema/dumber/internal/infrastructure/colorscheme"
11	"github.com/bnema/dumber/internal/infrastructure/config"	12		"github.com/bnema/dumber/internal/infrastructure/config"
12	"github.com/bnema/dumber/internal/infrastructure/desktop"	13		"github.com/bnema/dumber/internal/infrastructure/desktop"
		14	+	"github.com/rs/zerolog"
13	)	15		)
14		16
15	func TestLaunchModeFromArgs_DetectsStandaloneOmnibox(t *testing.T) {	17		func TestLaunchModeFromArgs_DetectsStandaloneOmnibox(t *testing.T) {

@@ -172,6 +174,20 @@ func TestResolveCurrentExecutable_PropagatesError(t *testing.T) {
172	}	174		}
173	}	175		}
174		176
		177	+	func TestWebKitGUIStartupDoesNotActivateCEFTrace(t *testing.T) {
		178	+	cfg := &config.Config{}
		179	+	cfg.Engine.Type = config.EngineTypeWebKit
		180	+	activationCalls := 0
		181	+
		182	+	activateCEFStartupTraceForGUI(cfg, startupTiming{}, nil, func(time.Time, time.Time, *zerolog.Logger) {
		183	+	activationCalls++
		184	+	})
		185	+
		186	+	if activationCalls != 0 {
		187	+	t.Fatal("WebKit GUI startup must not initialize, record, or summarize the CEF first-presentation trace")
		188	+	}
		189	+	}
		190	+
175	func TestPreInitializeAdwaitaForCEF_InitializesAndMarksDetector(t *testing.T) {	191		func TestPreInitializeAdwaitaForCEF_InitializesAndMarksDetector(t *testing.T) {
176	initResult := &bootstrap.ParallelInitResult{	192		initResult := &bootstrap.ParallelInitResult{
177	AdwaitaDetector: colorscheme.NewAdwaitaDetector(),	193		AdwaitaDetector: colorscheme.NewAdwaitaDetector(),

M docs/first-presentation.md +23 -7

@@ -1,7 +1,14 @@
1		-	# First presentation startup trace
	1	+	# CEF accelerated first-presentation startup trace
2	2
3		-	Dumber records one cold-start timeline for each GUI process. The trace begins
4		-	at `process_entry`, before CEF subprocess handling, and accepts these one-shot
	3	+	Dumber records this cold-start timeline **only for the accelerated CEF → DMABUF
	4	+	→ GTK path**. It is not a backend-neutral startup metric: the WebKit backend
	5	+	does not add milestones to this trace and never emits this CEF summary.
	6	+
	7	+	For a selected CEF GUI process, Dumber captures neutral `process_entry` and
	8	+	`config_complete` timestamps, then activates and seeds this CEF-owned trace only
	9	+	after configuration selects CEF. CEF helper processes, WebKit GUI startup, the
	10	+	standalone omnibox, and CLI commands never initialize this trace, record its
	11	+	milestones, or emit its summary. A selected CEF GUI trace accepts these one-shot
5	12		milestones only in order:
6	13
7	14		1. `process_entry`

@@ -13,11 +20,19 @@ milestones only in order:
13	20		7. `first_dmabuf_texture_swap` (after `GtkPicture.SetPaintable` succeeds)
14	21		8. `first_gtk_presentation` (the subsequent GTK frame-clock after-paint)
15	22
16		-	CEF library-load completion is intentionally not recorded: `InitWithApp` is an
	23	+	The CEF-to-GTK bridge owns the native accelerated-paint, DMABUF texture-swap,
	24	+	and GTK presentation boundaries. Dumber records the bridge's ordered callbacks;
	25	+	it does not synthesize them for another engine or rendering path. CEF
	26	+	library-load completion is intentionally not recorded: `InitWithApp` is an
17	27		opaque operation. Duplicate, unknown, and out-of-order transitions are
18	28		rejected. At the last milestone Dumber emits exactly one normal-level JSON
19		-	summary (`startup_trace: first presentation`) with the selected `backend`, an
20		-	`incomplete_reason`, total milliseconds, and monotonic milestones.
	29	+	summary (`startup_trace: first presentation`) with the selected CEF render
	30	+	backend, an `incomplete_reason`, total milliseconds, and monotonic milestones.
	31	+
	32	+	A non-DMABUF CEF backend or a missing accelerated callback does not produce a
	33	+	complete summary and is not comparable with this measurement. In particular,
	34	+	WebKit startup must be measured with a separately defined WebKit-specific
	35	+	contract rather than this CEF trace.
21	36
22	37		## Reproducible collection
23	38

@@ -29,7 +44,8 @@ DUMBER_MACHINE_GPU_PROFILE=integrated-gpu \
29	44		scripts/collect_first_presentation.sh
30	45		```
31	46
32		-	By default each collection is a fresh directory below
	47	+	The collector is for the accelerated CEF/DMABUF/GTK contract above. By default
	48	+	each collection is a fresh directory below
33	49		`$XDG_STATE_HOME/dumber/roadmap-evidence` (or
34	50		`$HOME/.local/state/dumber/roadmap-evidence` when `XDG_STATE_HOME` is unset),
35	51		not in the repository. `DUMBER_FIRST_PRESENTATION_OUTPUT` may override it only

-# First presentation startup trace
+# CEF accelerated first-presentation startup trace
-Dumber records one cold-start timeline for each GUI process. The trace begins
+Dumber records this cold-start timeline **only for the accelerated CEF → DMABUF
-at `process_entry`, before CEF subprocess handling, and accepts these one-shot
+→ 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`
 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
+summary (`startup_trace: first presentation`) with the selected CEF render
-`incomplete_reason`, total milliseconds, and monotonic milestones.
+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
   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

M internal/infrastructure/cef/engine_init.go +3 -3


@@ -56,7 +56,7 @@ func NewEngine(
56	56		return nil, err
57	57		}
58	58		cef2gtk.ConfigureRenderStackEnvironment(renderStackPlan)
59		-	logging.Trace().SetBackend(renderStackPlan.Backend.String())
	59	+	activeStartupTrace().SetBackend(renderStackPlan.Backend.String())
60	60
61	61		settings, err := prepareCEFSettings(opts, paths, cfg, logger)
62	62		if err != nil {

@@ -218,11 +218,11 @@ func initializeCEF(eng Engine, settings purecef.Settings, logger zerolog.Logge
218	218		logger.Debug().Msg("cef: calling InitWithApp")
219	219		// InitWithApp encapsulates loading libcef, so only the begin boundary is
220	220		// observable here; do not invent a separate library-load completion event.
221		-	logging.Trace().Mark("cef_library_load_begin")
	221	+	activeStartupTrace().Mark("cef_library_load_begin")
222	222		if err := purecef.InitWithApp(settings, app); err != nil {
223	223		return fmt.Errorf("cef.InitWithApp: %w", err)
224	224		}
225		-	logging.Trace().Mark("cef_initialized")
	225	+	activeStartupTrace().Mark("cef_initialized")
226	226		if libcefPath := loadedLibCEFPath(); libcefPath != "" {
227	227		logger.Info().Str("libcef_path", libcefPath).Msg("cef: runtime library loaded")
228	228		} else {


@@ -56,7 +56,7 @@ func NewEngine(
56		return nil, err	56		return nil, err
57		}	57		}
58		cef2gtk.ConfigureRenderStackEnvironment(renderStackPlan)	58		cef2gtk.ConfigureRenderStackEnvironment(renderStackPlan)
59	-	logging.Trace().SetBackend(renderStackPlan.Backend.String())	59	+	activeStartupTrace().SetBackend(renderStackPlan.Backend.String())
60			60
61		settings, err := prepareCEFSettings(opts, paths, cfg, logger)	61		settings, err := prepareCEFSettings(opts, paths, cfg, logger)
62		if err != nil {	62		if err != nil {

@@ -218,11 +218,11 @@ func initializeCEF(eng Engine, settings purecef.Settings, logger zerolog.Logge
218		logger.Debug().Msg("cef: calling InitWithApp")	218		logger.Debug().Msg("cef: calling InitWithApp")
219		// InitWithApp encapsulates loading libcef, so only the begin boundary is	219		// InitWithApp encapsulates loading libcef, so only the begin boundary is
220		// observable here; do not invent a separate library-load completion event.	220		// observable here; do not invent a separate library-load completion event.
221	-	logging.Trace().Mark("cef_library_load_begin")	221	+	activeStartupTrace().Mark("cef_library_load_begin")
222		if err := purecef.InitWithApp(settings, app); err != nil {	222		if err := purecef.InitWithApp(settings, app); err != nil {
223		return fmt.Errorf("cef.InitWithApp: %w", err)	223		return fmt.Errorf("cef.InitWithApp: %w", err)
224		}	224		}
225	-	logging.Trace().Mark("cef_initialized")	225	+	activeStartupTrace().Mark("cef_initialized")
226		if libcefPath := loadedLibCEFPath(); libcefPath != "" {	226		if libcefPath := loadedLibCEFPath(); libcefPath != "" {
227		logger.Info().Str("libcef_path", libcefPath).Msg("cef: runtime library loaded")	227		logger.Info().Str("libcef_path", libcefPath).Msg("cef: runtime library loaded")
228		} else {	228		} else {

M internal/infrastructure/cef/factory.go +1 -1


@@ -279,7 +279,7 @@ func (f WebViewFactory) postPendingBrowserCreate(ctx context.Context, wv WebVi
279	279		// OnAfterCreated once the host is fully wired.
280	280		initialURL := "about:blank"
281	281		// This is the request boundary, not the later OnAfterCreated callback.
282		-	logging.Trace().Mark("browser_create_requested")
	282	+	activeStartupTrace().Mark("browser_create_requested")
283	283		result := cefBrowserHostCreateBrowser(
284	284		pc.windowInfo,
285	285		pc.client,


@@ -279,7 +279,7 @@ func (f WebViewFactory) postPendingBrowserCreate(ctx context.Context, wv WebVi
279		// OnAfterCreated once the host is fully wired.	279		// OnAfterCreated once the host is fully wired.
280		initialURL := "about:blank"	280		initialURL := "about:blank"
281		// This is the request boundary, not the later OnAfterCreated callback.	281		// This is the request boundary, not the later OnAfterCreated callback.
282	-	logging.Trace().Mark("browser_create_requested")	282	+	activeStartupTrace().Mark("browser_create_requested")
283		result := cefBrowserHostCreateBrowser(	283		result := cefBrowserHostCreateBrowser(
284		pc.windowInfo,	284		pc.windowInfo,
285		pc.client,	285		pc.client,

R internal/logging/first_presentation_collector_test.go → internal/infrastructure/cef/first_presentation_collector_test.go +9 -9 renamed, 96% similar

@@ -1,4 +1,4 @@
1		-	package logging
	1	+	package cef
2	2
3	3		import (
4	4		"encoding/json"

@@ -23,7 +23,7 @@ const validFirstPresentationLog = `{"message":"startup_trace: milestone","milest
23	23		{"message":"startup_trace: first presentation","backend":"gdk-dmabuf","incomplete_reason":"","total_ms":7,"host":"alice"}`
24	24
25	25		func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testing.T) {
26		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	26	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
27	27		require.NoError(t, err)
28	28		script, err := os.ReadFile(filepath.Join(repoRoot, "scripts", "collect_first_presentation.sh"))
29	29		require.NoError(t, err)

@@ -32,7 +32,7 @@ func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testin
32	32		}
33	33
34	34		func TestFirstPresentationCollectorRejectsUnsafeOutputPaths(t *testing.T) {
35		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	35	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
36	36		require.NoError(t, err)
37	37		temp := t.TempDir()
38	38		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -109,7 +109,7 @@ func requireFileContents(t *testing.T, path, want string) {
109	109		}
110	110
111	111		func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {
112		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	112	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
113	113		require.NoError(t, err)
114	114		temp := t.TempDir()
115	115		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -169,7 +169,7 @@ func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {
169	169		}
170	170
171	171		func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *testing.T) {
172		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	172	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
173	173		require.NoError(t, err)
174	174		temp := t.TempDir()
175	175		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -218,7 +218,7 @@ func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *t
218	218		}
219	219
220	220		func TestFirstPresentationCollectorRejectsNonImmutableModuleProvenanceWithoutLeaks(t *testing.T) {
221		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	221	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
222	222		require.NoError(t, err)
223	223
224	224		for _, test := range []struct {

@@ -298,7 +298,7 @@ exit 1
298	298		}
299	299
300	300		func TestFirstPresentationCollectorDefaultsToXDGStateEvidenceDirectory(t *testing.T) {
301		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	301	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
302	302		require.NoError(t, err)
303	303		temp := t.TempDir()
304	304		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -342,7 +342,7 @@ func envWithout(name string) []string {
342	342		}
343	343
344	344		func TestFirstPresentationCollectorReadsProvenanceWithScopedGitSafeDirectory(t *testing.T) {
345		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	345	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
346	346		require.NoError(t, err)
347	347		temp := t.TempDir()
348	348		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -386,7 +386,7 @@ exit 128
386	386		}
387	387
388	388		func TestFirstPresentationCollectorRejectsInconsistentTiming(t *testing.T) {
389		-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))
	389	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
390	390		require.NoError(t, err)
391	391
392	392		for _, test := range []struct {

@@ -1,4 +1,4 @@
1	-	package logging	1	+	package cef
2			2
3		import (	3		import (
4		"encoding/json"	4		"encoding/json"

@@ -23,7 +23,7 @@ const validFirstPresentationLog = `{"message":"startup_trace: milestone","milest
23		{"message":"startup_trace: first presentation","backend":"gdk-dmabuf","incomplete_reason":"","total_ms":7,"host":"alice"}`	23		{"message":"startup_trace: first presentation","backend":"gdk-dmabuf","incomplete_reason":"","total_ms":7,"host":"alice"}`
24			24
25		func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testing.T) {	25		func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testing.T) {
26	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	26	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
27		require.NoError(t, err)	27		require.NoError(t, err)
28		script, err := os.ReadFile(filepath.Join(repoRoot, "scripts", "collect_first_presentation.sh"))	28		script, err := os.ReadFile(filepath.Join(repoRoot, "scripts", "collect_first_presentation.sh"))
29		require.NoError(t, err)	29		require.NoError(t, err)

@@ -32,7 +32,7 @@ func TestFirstPresentationCollectorNeverRecursivelyDeletesCallerOutput(t *testin
32		}	32		}
33			33
34		func TestFirstPresentationCollectorRejectsUnsafeOutputPaths(t *testing.T) {	34		func TestFirstPresentationCollectorRejectsUnsafeOutputPaths(t *testing.T) {
35	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	35	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
36		require.NoError(t, err)	36		require.NoError(t, err)
37		temp := t.TempDir()	37		temp := t.TempDir()
38		runtime := filepath.Join(temp, "cef-147-runtime")	38		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -109,7 +109,7 @@ func requireFileContents(t *testing.T, path, want string) {
109		}	109		}
110			110
111		func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {	111		func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {
112	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	112	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
113		require.NoError(t, err)	113		require.NoError(t, err)
114		temp := t.TempDir()	114		temp := t.TempDir()
115		runtime := filepath.Join(temp, "cef-147-runtime")	115		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -169,7 +169,7 @@ func TestFirstPresentationCollectorSanitizesMachineLocalValues(t *testing.T) {
169		}	169		}
170			170
171		func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *testing.T) {	171		func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *testing.T) {
172	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	172	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
173		require.NoError(t, err)	173		require.NoError(t, err)
174		temp := t.TempDir()	174		temp := t.TempDir()
175		runtime := filepath.Join(temp, "cef-147-runtime")	175		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -218,7 +218,7 @@ func TestFirstPresentationCollectorDerivesSelectedImmutableModuleProvenance(t *t
218		}	218		}
219			219
220		func TestFirstPresentationCollectorRejectsNonImmutableModuleProvenanceWithoutLeaks(t *testing.T) {	220		func TestFirstPresentationCollectorRejectsNonImmutableModuleProvenanceWithoutLeaks(t *testing.T) {
221	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	221	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
222		require.NoError(t, err)	222		require.NoError(t, err)
223			223
224		for _, test := range []struct {	224		for _, test := range []struct {

@@ -298,7 +298,7 @@ exit 1
298		}	298		}
299			299
300		func TestFirstPresentationCollectorDefaultsToXDGStateEvidenceDirectory(t *testing.T) {	300		func TestFirstPresentationCollectorDefaultsToXDGStateEvidenceDirectory(t *testing.T) {
301	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	301	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
302		require.NoError(t, err)	302		require.NoError(t, err)
303		temp := t.TempDir()	303		temp := t.TempDir()
304		runtime := filepath.Join(temp, "cef-147-runtime")	304		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -342,7 +342,7 @@ func envWithout(name string) []string {
342		}	342		}
343			343
344		func TestFirstPresentationCollectorReadsProvenanceWithScopedGitSafeDirectory(t *testing.T) {	344		func TestFirstPresentationCollectorReadsProvenanceWithScopedGitSafeDirectory(t *testing.T) {
345	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	345	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
346		require.NoError(t, err)	346		require.NoError(t, err)
347		temp := t.TempDir()	347		temp := t.TempDir()
348		runtime := filepath.Join(temp, "cef-147-runtime")	348		runtime := filepath.Join(temp, "cef-147-runtime")

@@ -386,7 +386,7 @@ exit 128
386		}	386		}
387			387
388		func TestFirstPresentationCollectorRejectsInconsistentTiming(t *testing.T) {	388		func TestFirstPresentationCollectorRejectsInconsistentTiming(t *testing.T) {
389	-	repoRoot, err := filepath.Abs(filepath.Join("..", ".."))	389	+	repoRoot, err := filepath.Abs(filepath.Join("..", "..", ".."))
390		require.NoError(t, err)	390		require.NoError(t, err)
391			391
392		for _, test := range []struct {	392		for _, test := range []struct {

M internal/infrastructure/cef/render_handler_adapter.go +6 -6


@@ -26,19 +26,19 @@ var _ purecef.RenderHandler = (*dumberRenderHandler)(nil)
26	26		// startupPresentationHooks consumes the one-shot facts emitted by
27	27		// purego-cef2gtk. The bridge owns the native DMABUF and frame-clock boundaries;
28	28		// Dumber only records their ordered application-level timeline.
29		-	func startupPresentationHooks() cef2gtk.Hooks {
	29	+	func startupPresentationHooks(trace *startupTrace) cef2gtk.Hooks {
30	30		return cef2gtk.Hooks{
31	31		OnFirstAcceleratedPaint: func() {
32		-	logging.Trace().Mark("first_accelerated_paint_received")
	32	+	trace.Mark("first_accelerated_paint_received")
33	33		},
34	34		OnFirstDMABUFTextureSwap: func() {
35		-	logging.Trace().Mark("first_dmabuf_texture_swap")
	35	+	trace.Mark("first_dmabuf_texture_swap")
36	36		},
37	37		OnFirstPresentation: func() {
38		-	logging.Trace().MarkGTKAfterPaint()
	38	+	trace.MarkGTKAfterPaint()
39	39		},
40	40		OnDMABUFUnsupported: func() {
41		-	logging.Trace().SetIncompleteReason("dmabuf_texture_swap_unavailable")
	41	+	trace.SetIncompleteReason("dmabuf_texture_swap_unavailable")
42	42		},
43	43		}
44	44		}

@@ -50,7 +50,7 @@ func newDumberRenderHandler(wv *WebView) purecef.RenderHandler {
50	50		h := &dumberRenderHandler{wv: wv}
51	51
52	52		var unsupportedPaintOnce sync.Once
53		-	hooks := startupPresentationHooks()
	53	+	hooks := startupPresentationHooks(activeStartupTrace())
54	54		hooks.OnUnsupportedPaint = func() {
55	55		unsupportedPaintOnce.Do(func() {
56	56		if wv.ctx != nil {


@@ -26,19 +26,19 @@ var _ purecef.RenderHandler = (*dumberRenderHandler)(nil)
26		// startupPresentationHooks consumes the one-shot facts emitted by	26		// startupPresentationHooks consumes the one-shot facts emitted by
27		// purego-cef2gtk. The bridge owns the native DMABUF and frame-clock boundaries;	27		// purego-cef2gtk. The bridge owns the native DMABUF and frame-clock boundaries;
28		// Dumber only records their ordered application-level timeline.	28		// Dumber only records their ordered application-level timeline.
29	-	func startupPresentationHooks() cef2gtk.Hooks {	29	+	func startupPresentationHooks(trace *startupTrace) cef2gtk.Hooks {
30		return cef2gtk.Hooks{	30		return cef2gtk.Hooks{
31		OnFirstAcceleratedPaint: func() {	31		OnFirstAcceleratedPaint: func() {
32	-	logging.Trace().Mark("first_accelerated_paint_received")	32	+	trace.Mark("first_accelerated_paint_received")
33		},	33		},
34		OnFirstDMABUFTextureSwap: func() {	34		OnFirstDMABUFTextureSwap: func() {
35	-	logging.Trace().Mark("first_dmabuf_texture_swap")	35	+	trace.Mark("first_dmabuf_texture_swap")
36		},	36		},
37		OnFirstPresentation: func() {	37		OnFirstPresentation: func() {
38	-	logging.Trace().MarkGTKAfterPaint()	38	+	trace.MarkGTKAfterPaint()
39		},	39		},
40		OnDMABUFUnsupported: func() {	40		OnDMABUFUnsupported: func() {
41	-	logging.Trace().SetIncompleteReason("dmabuf_texture_swap_unavailable")	41	+	trace.SetIncompleteReason("dmabuf_texture_swap_unavailable")
42		},	42		},
43		}	43		}
44		}	44		}

@@ -50,7 +50,7 @@ func newDumberRenderHandler(wv *WebView) purecef.RenderHandler {
50		h := &dumberRenderHandler{wv: wv}	50		h := &dumberRenderHandler{wv: wv}
51			51
52		var unsupportedPaintOnce sync.Once	52		var unsupportedPaintOnce sync.Once
53	-	hooks := startupPresentationHooks()	53	+	hooks := startupPresentationHooks(activeStartupTrace())
54		hooks.OnUnsupportedPaint = func() {	54		hooks.OnUnsupportedPaint = func() {
55		unsupportedPaintOnce.Do(func() {	55		unsupportedPaintOnce.Do(func() {
56		if wv.ctx != nil {	56		if wv.ctx != nil {

M internal/infrastructure/cef/startup_presentation_hooks_test.go +64 -1

@@ -1,16 +1,79 @@
1	1		package cef
2	2
3	3		import (
	4	+	"bytes"
	5	+	"encoding/json"
	6	+	"strings"
4	7		"testing"
	8	+	"time"
5	9
	10	+	"github.com/rs/zerolog"
6	11		"github.com/stretchr/testify/require"
7	12		)
8	13
9	14		func TestStartupPresentationHooksWireEveryUpstreamFirstPresentationCallback(t *testing.T) {
10		-	hooks := startupPresentationHooks()
	15	+	var output bytes.Buffer
	16	+	trace := newStartupTrace(time.Now, time.Now())
	17	+	trace.SetBackend("gdk-dmabuf")
	18	+	logger := zerolog.New(&output)
	19	+	trace.SetLogger(&logger)
	20	+	for _, milestone := range []string{
	21	+	"process_entry",
	22	+	"config_complete",
	23	+	"cef_library_load_begin",
	24	+	"cef_initialized",
	25	+	"browser_create_requested",
	26	+	} {
	27	+	require.Truef(t, trace.Mark(milestone), "seed milestone %q", milestone)
	28	+	}
11	29
	30	+	hooks := startupPresentationHooks(trace)
12	31		require.NotNil(t, hooks.OnFirstAcceleratedPaint)
13	32		require.NotNil(t, hooks.OnFirstDMABUFTextureSwap)
14	33		require.NotNil(t, hooks.OnFirstPresentation)
15	34		require.NotNil(t, hooks.OnDMABUFUnsupported)
	35	+
	36	+	// The unsupported fact may arrive before the successful presentation path.
	37	+	// Each callback is invoked twice to make no-op, swapped, and duplicate bodies
	38	+	// observable through the exact trace output below.
	39	+	hooks.OnDMABUFUnsupported()
	40	+	hooks.OnDMABUFUnsupported()
	41	+	hooks.OnFirstAcceleratedPaint()
	42	+	hooks.OnFirstAcceleratedPaint()
	43	+	hooks.OnFirstDMABUFTextureSwap()
	44	+	hooks.OnFirstDMABUFTextureSwap()
	45	+	hooks.OnFirstPresentation()
	46	+	hooks.OnFirstPresentation()
	47	+
	48	+	var milestones []string
	49	+	summaryCount := 0
	50	+	var incompleteReason string
	51	+	for _, line := range strings.Split(strings.TrimSpace(output.String()), "\n") {
	52	+	var event struct {
	53	+	Message string `json:"message"`
	54	+	Milestone string `json:"milestone"`
	55	+	IncompleteReason string `json:"incomplete_reason"`
	56	+	}
	57	+	require.NoError(t, json.Unmarshal([]byte(line), &event))
	58	+	switch event.Message {
	59	+	case "startup_trace: milestone":
	60	+	milestones = append(milestones, event.Milestone)
	61	+	case "startup_trace: first presentation":
	62	+	summaryCount++
	63	+	incompleteReason = event.IncompleteReason
	64	+	}
	65	+	}
	66	+
	67	+	require.Equal(t, []string{
	68	+	"process_entry",
	69	+	"config_complete",
	70	+	"cef_library_load_begin",
	71	+	"cef_initialized",
	72	+	"browser_create_requested",
	73	+	"first_accelerated_paint_received",
	74	+	"first_dmabuf_texture_swap",
	75	+	"first_gtk_presentation",
	76	+	}, milestones)
	77	+	require.Equal(t, "dmabuf_texture_swap_unavailable", incompleteReason)
	78	+	require.Equal(t, 1, summaryCount)
16	79		}

@@ -1,16 +1,79 @@
1		package cef	1		package cef
2			2
3		import (	3		import (
			4	+	"bytes"
			5	+	"encoding/json"
			6	+	"strings"
4		"testing"	7		"testing"
			8	+	"time"
5			9
			10	+	"github.com/rs/zerolog"
6		"github.com/stretchr/testify/require"	11		"github.com/stretchr/testify/require"
7		)	12		)
8			13
9		func TestStartupPresentationHooksWireEveryUpstreamFirstPresentationCallback(t *testing.T) {	14		func TestStartupPresentationHooksWireEveryUpstreamFirstPresentationCallback(t *testing.T) {
10	-	hooks := startupPresentationHooks()	15	+	var output bytes.Buffer
			16	+	trace := newStartupTrace(time.Now, time.Now())
			17	+	trace.SetBackend("gdk-dmabuf")
			18	+	logger := zerolog.New(&output)
			19	+	trace.SetLogger(&logger)
			20	+	for _, milestone := range []string{
			21	+	"process_entry",
			22	+	"config_complete",
			23	+	"cef_library_load_begin",
			24	+	"cef_initialized",
			25	+	"browser_create_requested",
			26	+	} {
			27	+	require.Truef(t, trace.Mark(milestone), "seed milestone %q", milestone)
			28	+	}
11			29
			30	+	hooks := startupPresentationHooks(trace)
12		require.NotNil(t, hooks.OnFirstAcceleratedPaint)	31		require.NotNil(t, hooks.OnFirstAcceleratedPaint)
13		require.NotNil(t, hooks.OnFirstDMABUFTextureSwap)	32		require.NotNil(t, hooks.OnFirstDMABUFTextureSwap)
14		require.NotNil(t, hooks.OnFirstPresentation)	33		require.NotNil(t, hooks.OnFirstPresentation)
15		require.NotNil(t, hooks.OnDMABUFUnsupported)	34		require.NotNil(t, hooks.OnDMABUFUnsupported)
			35	+
			36	+	// The unsupported fact may arrive before the successful presentation path.
			37	+	// Each callback is invoked twice to make no-op, swapped, and duplicate bodies
			38	+	// observable through the exact trace output below.
			39	+	hooks.OnDMABUFUnsupported()
			40	+	hooks.OnDMABUFUnsupported()
			41	+	hooks.OnFirstAcceleratedPaint()
			42	+	hooks.OnFirstAcceleratedPaint()
			43	+	hooks.OnFirstDMABUFTextureSwap()
			44	+	hooks.OnFirstDMABUFTextureSwap()
			45	+	hooks.OnFirstPresentation()
			46	+	hooks.OnFirstPresentation()
			47	+
			48	+	var milestones []string
			49	+	summaryCount := 0
			50	+	var incompleteReason string
			51	+	for _, line := range strings.Split(strings.TrimSpace(output.String()), "\n") {
			52	+	var event struct {
			53	+	Message string `json:"message"`
			54	+	Milestone string `json:"milestone"`
			55	+	IncompleteReason string `json:"incomplete_reason"`
			56	+	}
			57	+	require.NoError(t, json.Unmarshal([]byte(line), &event))
			58	+	switch event.Message {
			59	+	case "startup_trace: milestone":
			60	+	milestones = append(milestones, event.Milestone)
			61	+	case "startup_trace: first presentation":
			62	+	summaryCount++
			63	+	incompleteReason = event.IncompleteReason
			64	+	}
			65	+	}
			66	+
			67	+	require.Equal(t, []string{
			68	+	"process_entry",
			69	+	"config_complete",
			70	+	"cef_library_load_begin",
			71	+	"cef_initialized",
			72	+	"browser_create_requested",
			73	+	"first_accelerated_paint_received",
			74	+	"first_dmabuf_texture_swap",
			75	+	"first_gtk_presentation",
			76	+	}, milestones)
			77	+	require.Equal(t, "dmabuf_texture_swap_unavailable", incompleteReason)
			78	+	require.Equal(t, 1, summaryCount)
16		}	79		}

A internal/infrastructure/cef/startup_trace.go +199 -0

@@ -0,0 +1,199 @@
	1	+	package cef
	2	+
	3	+	import (
	4	+	"sync"
	5	+	"time"
	6	+
	7	+	"github.com/rs/zerolog"
	8	+	)
	9	+
	10	+	// startupTrace records the accelerated CEF/DMABUF/GTK path from process entry
	11	+	// to the first GTK presentation. It deliberately rejects unknown, duplicate,
	12	+	// and out-of-order milestones so collected cold-start measurements remain
	13	+	// truthful.
	14	+	type startupTrace struct {
	15	+	mu sync.Mutex
	16	+	now func() time.Time
	17	+	t0 time.Time
	18	+	milestones []startupMilestone
	19	+	logger *zerolog.Logger
	20	+	buffered []startupMilestone
	21	+	backend string
	22	+	incompleteReason string
	23	+	summaryEmitted bool
	24	+	}
	25	+
	26	+	type startupMilestone struct {
	27	+	Name string
	28	+	Elapsed time.Duration
	29	+	Delta time.Duration
	30	+	}
	31	+
	32	+	var startupMilestoneOrder = []string{
	33	+	"process_entry",
	34	+	"config_complete",
	35	+	"cef_library_load_begin",
	36	+	"cef_initialized",
	37	+	"browser_create_requested",
	38	+	"first_accelerated_paint_received",
	39	+	"first_dmabuf_texture_swap",
	40	+	"first_gtk_presentation",
	41	+	}
	42	+
	43	+	var processStartupTrace struct {
	44	+	sync.Mutex
	45	+	trace *startupTrace
	46	+	}
	47	+
	48	+	func newStartupTrace(now func() time.Time, processEntry time.Time) *startupTrace {
	49	+	return &startupTrace{
	50	+	now: now,
	51	+	t0: processEntry,
	52	+	milestones: make([]startupMilestone, 0, len(startupMilestoneOrder)),
	53	+	buffered: make([]startupMilestone, 0, len(startupMilestoneOrder)),
	54	+	}
	55	+	}
	56	+
	57	+	// ActivateStartupTrace starts the CEF-only first-presentation trace after GUI
	58	+	// engine selection. The supplied timestamps are captured by the application at
	59	+	// process entry and configuration completion, before CEF initialization.
	60	+	func ActivateStartupTrace(processEntry, configComplete time.Time, logger *zerolog.Logger) {
	61	+	if processEntry.IsZero() \|\| configComplete.IsZero() {
	62	+	return
	63	+	}
	64	+
	65	+	processStartupTrace.Lock()
	66	+	defer processStartupTrace.Unlock()
	67	+	if processStartupTrace.trace != nil {
	68	+	return
	69	+	}
	70	+
	71	+	trace := newStartupTrace(time.Now, processEntry)
	72	+	if !trace.markAt("process_entry", processEntry) \|\| !trace.markAt("config_complete", configComplete) {
	73	+	return
	74	+	}
	75	+	trace.SetLogger(logger)
	76	+	processStartupTrace.trace = trace
	77	+	}
	78	+
	79	+	func activeStartupTrace() *startupTrace {
	80	+	processStartupTrace.Lock()
	81	+	defer processStartupTrace.Unlock()
	82	+	return processStartupTrace.trace
	83	+	}
	84	+
	85	+	func (st startupTrace) SetLogger(logger zerolog.Logger) {
	86	+	if st == nil \|\| logger == nil {
	87	+	return
	88	+	}
	89	+	st.mu.Lock()
	90	+	defer st.mu.Unlock()
	91	+	st.logger = logger
	92	+	for _, milestone := range st.buffered {
	93	+	st.emitMilestone(milestone)
	94	+	}
	95	+	st.buffered = nil
	96	+	st.emitSummaryLocked()
	97	+	}
	98	+
	99	+	func (st *startupTrace) SetBackend(backend string) {
	100	+	if st == nil {
	101	+	return
	102	+	}
	103	+	st.mu.Lock()
	104	+	defer st.mu.Unlock()
	105	+	st.backend = backend
	106	+	}
	107	+
	108	+	func (st *startupTrace) SetIncompleteReason(reason string) {
	109	+	if st == nil {
	110	+	return
	111	+	}
	112	+	st.mu.Lock()
	113	+	defer st.mu.Unlock()
	114	+	if st.incompleteReason == "" {
	115	+	st.incompleteReason = reason
	116	+	}
	117	+	}
	118	+
	119	+	// Mark accepts exactly the next non-presentation startup milestone.
	120	+	func (st *startupTrace) Mark(name string) bool {
	121	+	if name == "first_gtk_presentation" {
	122	+	return false
	123	+	}
	124	+	return st.markAt(name, st.currentTime())
	125	+	}
	126	+
	127	+	// MarkGTKAfterPaint records the final milestone from the CEF-to-GTK bridge's
	128	+	// first frame-clock after-paint callback.
	129	+	func (st *startupTrace) MarkGTKAfterPaint() bool {
	130	+	return st.markAt("first_gtk_presentation", st.currentTime())
	131	+	}
	132	+
	133	+	func (st *startupTrace) currentTime() time.Time {
	134	+	if st == nil \|\| st.now == nil {
	135	+	return time.Time{}
	136	+	}
	137	+	return st.now()
	138	+	}
	139	+
	140	+	func (st *startupTrace) markAt(name string, at time.Time) bool {
	141	+	if st == nil \|\| st.now == nil \|\| at.IsZero() {
	142	+	return false
	143	+	}
	144	+	st.mu.Lock()
	145	+	defer st.mu.Unlock()
	146	+	if at.Before(st.t0) \|\| len(st.milestones) >= len(startupMilestoneOrder) \|\| name != startupMilestoneOrder[len(st.milestones)] {
	147	+	return false
	148	+	}
	149	+
	150	+	milestone := startupMilestone{Name: name, Elapsed: at.Sub(st.t0)}
	151	+	previousMilliseconds := int64(0)
	152	+	if len(st.milestones) > 0 {
	153	+	previousMilliseconds = st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()
	154	+	}
	155	+	milestone.Delta = time.Duration(milestone.Elapsed.Milliseconds()-previousMilliseconds) * time.Millisecond
	156	+	st.milestones = append(st.milestones, milestone)
	157	+	if st.logger == nil {
	158	+	st.buffered = append(st.buffered, milestone)
	159	+	} else {
	160	+	st.emitMilestone(milestone)
	161	+	}
	162	+	st.emitSummaryLocked()
	163	+	return true
	164	+	}
	165	+
	166	+	func (st *startupTrace) emitMilestone(m startupMilestone) {
	167	+	if st.logger == nil {
	168	+	return
	169	+	}
	170	+	st.logger.Debug().
	171	+	Str("milestone", m.Name).
	172	+	Int64("t_ms", m.Elapsed.Milliseconds()).
	173	+	Int64("delta_ms", m.Delta.Milliseconds()).
	174	+	Msg("startup_trace: milestone")
	175	+	}
	176	+
	177	+	func (st *startupTrace) emitSummaryLocked() {
	178	+	if st.summaryEmitted \|\| st.logger == nil \|\| len(st.milestones) != len(startupMilestoneOrder) {
	179	+	return
	180	+	}
	181	+	st.summaryEmitted = true
	182	+	st.logger.Info().
	183	+	Str("backend", st.backend).
	184	+	Str("incomplete_reason", st.incompleteReason).
	185	+	Int64("total_ms", st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()).
	186	+	Interface("milestones", st.milestones).
	187	+	Msg("startup_trace: first presentation")
	188	+	}
	189	+
	190	+	func (st *startupTrace) Enabled() bool { return st != nil && st.now != nil }
	191	+
	192	+	func (st *startupTrace) TotalElapsed() time.Duration {
	193	+	if st == nil \|\| st.now == nil {
	194	+	return 0
	195	+	}
	196	+	st.mu.Lock()
	197	+	defer st.mu.Unlock()
	198	+	return st.now().Sub(st.t0)
	199	+	}

@@ -0,0 +1,199 @@
	1	+	package cef
	2	+
	3	+	import (
	4	+	"sync"
	5	+	"time"
	6	+
	7	+	"github.com/rs/zerolog"
	8	+	)
	9	+
	10	+	// startupTrace records the accelerated CEF/DMABUF/GTK path from process entry
	11	+	// to the first GTK presentation. It deliberately rejects unknown, duplicate,
	12	+	// and out-of-order milestones so collected cold-start measurements remain
	13	+	// truthful.
	14	+	type startupTrace struct {
	15	+	mu sync.Mutex
	16	+	now func() time.Time
	17	+	t0 time.Time
	18	+	milestones []startupMilestone
	19	+	logger *zerolog.Logger
	20	+	buffered []startupMilestone
	21	+	backend string
	22	+	incompleteReason string
	23	+	summaryEmitted bool
	24	+	}
	25	+
	26	+	type startupMilestone struct {
	27	+	Name string
	28	+	Elapsed time.Duration
	29	+	Delta time.Duration
	30	+	}
	31	+
	32	+	var startupMilestoneOrder = []string{
	33	+	"process_entry",
	34	+	"config_complete",
	35	+	"cef_library_load_begin",
	36	+	"cef_initialized",
	37	+	"browser_create_requested",
	38	+	"first_accelerated_paint_received",
	39	+	"first_dmabuf_texture_swap",
	40	+	"first_gtk_presentation",
	41	+	}
	42	+
	43	+	var processStartupTrace struct {
	44	+	sync.Mutex
	45	+	trace *startupTrace
	46	+	}
	47	+
	48	+	func newStartupTrace(now func() time.Time, processEntry time.Time) *startupTrace {
	49	+	return &startupTrace{
	50	+	now: now,
	51	+	t0: processEntry,
	52	+	milestones: make([]startupMilestone, 0, len(startupMilestoneOrder)),
	53	+	buffered: make([]startupMilestone, 0, len(startupMilestoneOrder)),
	54	+	}
	55	+	}
	56	+
	57	+	// ActivateStartupTrace starts the CEF-only first-presentation trace after GUI
	58	+	// engine selection. The supplied timestamps are captured by the application at
	59	+	// process entry and configuration completion, before CEF initialization.
	60	+	func ActivateStartupTrace(processEntry, configComplete time.Time, logger *zerolog.Logger) {
	61	+	if processEntry.IsZero() \|\| configComplete.IsZero() {
	62	+	return
	63	+	}
	64	+
	65	+	processStartupTrace.Lock()
	66	+	defer processStartupTrace.Unlock()
	67	+	if processStartupTrace.trace != nil {
	68	+	return
	69	+	}
	70	+
	71	+	trace := newStartupTrace(time.Now, processEntry)
	72	+	if !trace.markAt("process_entry", processEntry) \|\| !trace.markAt("config_complete", configComplete) {
	73	+	return
	74	+	}
	75	+	trace.SetLogger(logger)
	76	+	processStartupTrace.trace = trace
	77	+	}
	78	+
	79	+	func activeStartupTrace() *startupTrace {
	80	+	processStartupTrace.Lock()
	81	+	defer processStartupTrace.Unlock()
	82	+	return processStartupTrace.trace
	83	+	}
	84	+
	85	+	func (st startupTrace) SetLogger(logger zerolog.Logger) {
	86	+	if st == nil \|\| logger == nil {
	87	+	return
	88	+	}
	89	+	st.mu.Lock()
	90	+	defer st.mu.Unlock()
	91	+	st.logger = logger
	92	+	for _, milestone := range st.buffered {
	93	+	st.emitMilestone(milestone)
	94	+	}
	95	+	st.buffered = nil
	96	+	st.emitSummaryLocked()
	97	+	}
	98	+
	99	+	func (st *startupTrace) SetBackend(backend string) {
	100	+	if st == nil {
	101	+	return
	102	+	}
	103	+	st.mu.Lock()
	104	+	defer st.mu.Unlock()
	105	+	st.backend = backend
	106	+	}
	107	+
	108	+	func (st *startupTrace) SetIncompleteReason(reason string) {
	109	+	if st == nil {
	110	+	return
	111	+	}
	112	+	st.mu.Lock()
	113	+	defer st.mu.Unlock()
	114	+	if st.incompleteReason == "" {
	115	+	st.incompleteReason = reason
	116	+	}
	117	+	}
	118	+
	119	+	// Mark accepts exactly the next non-presentation startup milestone.
	120	+	func (st *startupTrace) Mark(name string) bool {
	121	+	if name == "first_gtk_presentation" {
	122	+	return false
	123	+	}
	124	+	return st.markAt(name, st.currentTime())
	125	+	}
	126	+
	127	+	// MarkGTKAfterPaint records the final milestone from the CEF-to-GTK bridge's
	128	+	// first frame-clock after-paint callback.
	129	+	func (st *startupTrace) MarkGTKAfterPaint() bool {
	130	+	return st.markAt("first_gtk_presentation", st.currentTime())
	131	+	}
	132	+
	133	+	func (st *startupTrace) currentTime() time.Time {
	134	+	if st == nil \|\| st.now == nil {
	135	+	return time.Time{}
	136	+	}
	137	+	return st.now()
	138	+	}
	139	+
	140	+	func (st *startupTrace) markAt(name string, at time.Time) bool {
	141	+	if st == nil \|\| st.now == nil \|\| at.IsZero() {
	142	+	return false
	143	+	}
	144	+	st.mu.Lock()
	145	+	defer st.mu.Unlock()
	146	+	if at.Before(st.t0) \|\| len(st.milestones) >= len(startupMilestoneOrder) \|\| name != startupMilestoneOrder[len(st.milestones)] {
	147	+	return false
	148	+	}
	149	+
	150	+	milestone := startupMilestone{Name: name, Elapsed: at.Sub(st.t0)}
	151	+	previousMilliseconds := int64(0)
	152	+	if len(st.milestones) > 0 {
	153	+	previousMilliseconds = st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()
	154	+	}
	155	+	milestone.Delta = time.Duration(milestone.Elapsed.Milliseconds()-previousMilliseconds) * time.Millisecond
	156	+	st.milestones = append(st.milestones, milestone)
	157	+	if st.logger == nil {
	158	+	st.buffered = append(st.buffered, milestone)
	159	+	} else {
	160	+	st.emitMilestone(milestone)
	161	+	}
	162	+	st.emitSummaryLocked()
	163	+	return true
	164	+	}
	165	+
	166	+	func (st *startupTrace) emitMilestone(m startupMilestone) {
	167	+	if st.logger == nil {
	168	+	return
	169	+	}
	170	+	st.logger.Debug().
	171	+	Str("milestone", m.Name).
	172	+	Int64("t_ms", m.Elapsed.Milliseconds()).
	173	+	Int64("delta_ms", m.Delta.Milliseconds()).
	174	+	Msg("startup_trace: milestone")
	175	+	}
	176	+
	177	+	func (st *startupTrace) emitSummaryLocked() {
	178	+	if st.summaryEmitted \|\| st.logger == nil \|\| len(st.milestones) != len(startupMilestoneOrder) {
	179	+	return
	180	+	}
	181	+	st.summaryEmitted = true
	182	+	st.logger.Info().
	183	+	Str("backend", st.backend).
	184	+	Str("incomplete_reason", st.incompleteReason).
	185	+	Int64("total_ms", st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()).
	186	+	Interface("milestones", st.milestones).
	187	+	Msg("startup_trace: first presentation")
	188	+	}
	189	+
	190	+	func (st *startupTrace) Enabled() bool { return st != nil && st.now != nil }
	191	+
	192	+	func (st *startupTrace) TotalElapsed() time.Duration {
	193	+	if st == nil \|\| st.now == nil {
	194	+	return 0
	195	+	}
	196	+	st.mu.Lock()
	197	+	defer st.mu.Unlock()
	198	+	return st.now().Sub(st.t0)
	199	+	}

R internal/logging/startup_trace_test.go → internal/infrastructure/cef/startup_trace_test.go +44 -17 renamed, 50% similar

@@ -1,4 +1,4 @@
1		-	package logging
	1	+	package cef
2	2
3	3		import (
4	4		"bytes"

@@ -9,9 +9,37 @@ import (
9	9		"github.com/stretchr/testify/require"
10	10		)
11	11
	12	+	func TestActivateStartupTraceSeedsNeutralProcessAndConfigTiming(t *testing.T) {
	13	+	processStartupTrace.Lock()
	14	+	previous := processStartupTrace.trace
	15	+	processStartupTrace.trace = nil
	16	+	processStartupTrace.Unlock()
	17	+	t.Cleanup(func() {
	18	+	processStartupTrace.Lock()
	19	+	processStartupTrace.trace = previous
	20	+	processStartupTrace.Unlock()
	21	+	})
	22	+
	23	+	processEntry := time.Unix(100, 0)
	24	+	configComplete := processEntry.Add(15 * time.Millisecond)
	25	+	var output bytes.Buffer
	26	+	logger := zerolog.New(&output).Level(zerolog.DebugLevel)
	27	+
	28	+	ActivateStartupTrace(processEntry, configComplete, &logger)
	29	+	trace := activeStartupTrace()
	30	+
	31	+	require.NotNil(t, trace)
	32	+	require.Equal(t, []string{"process_entry", "config_complete"}, []string{trace.milestones[0].Name, trace.milestones[1].Name})
	33	+	require.Equal(t, int64(0), trace.milestones[0].Elapsed.Milliseconds())
	34	+	require.Equal(t, int64(15), trace.milestones[1].Elapsed.Milliseconds())
	35	+	require.Contains(t, output.String(), `"milestone":"process_entry"`)
	36	+	require.Contains(t, output.String(), `"milestone":"config_complete"`)
	37	+	require.NotContains(t, output.String(), `"message":"startup_trace: first presentation"`)
	38	+	}
	39	+
12	40		func TestStartupTraceAcceptsOnlyOrderedOneShotMilestones(t *testing.T) {
13	41		now := time.Unix(100, 0)
14		-	trace := newStartupTrace(func() time.Time { return now })
	42	+	trace := newStartupTrace(func() time.Time { return now }, now)
15	43
16	44		require.True(t, trace.Mark("process_entry"))
17	45		require.False(t, trace.Mark("cef_initialized"), "out-of-order transition must be rejected")

@@ -36,33 +64,32 @@ func TestStartupTraceAcceptsOnlyOrderedOneShotMilestones(t *testing.T) {
36	64		require.False(t, trace.Mark("first_gtk_presentation"))
37	65		}
38	66
39		-	func TestStartupTraceQuantizesDeltaToPublishedMilliseconds(t *testing.T) {
40		-	now := time.Unix(100, 0)
41		-	trace := newStartupTrace(func() time.Time { return now })
	67	+	func TestStartupTracePreservesProcessAndConfigTimestamps(t *testing.T) {
	68	+	processEntry := time.Unix(100, 0)
	69	+	configComplete := processEntry.Add(1500 * time.Microsecond)
	70	+	now := configComplete.Add(900 * time.Microsecond)
	71	+	trace := newStartupTrace(func() time.Time { return now }, processEntry)
42	72
43		-	now = now.Add(1500 * time.Microsecond)
44		-	require.True(t, trace.Mark("process_entry"))
45		-	now = now.Add(900 * time.Microsecond)
46		-	require.True(t, trace.Mark("config_complete"))
	73	+	require.True(t, trace.markAt("process_entry", processEntry))
	74	+	require.True(t, trace.markAt("config_complete", configComplete))
47	75
48		-	require.Equal(t, int64(1), trace.milestones[0].Elapsed.Milliseconds())
49		-	require.Equal(t, int64(1), trace.milestones[0].Delta.Milliseconds())
50		-	require.Equal(t, int64(2), trace.milestones[1].Elapsed.Milliseconds())
	76	+	require.Equal(t, int64(0), trace.milestones[0].Elapsed.Milliseconds())
	77	+	require.Equal(t, int64(0), trace.milestones[0].Delta.Milliseconds())
	78	+	require.Equal(t, int64(1), trace.milestones[1].Elapsed.Milliseconds())
51	79		require.Equal(t, int64(1), trace.milestones[1].Delta.Milliseconds())
52	80		}
53	81
54		-	func TestStartupTraceFinishCannotFabricateFirstGTKPresentation(t *testing.T) {
	82	+	func TestStartupTraceReservesFirstGTKPresentationForAfterPaint(t *testing.T) {
55	83		now := time.Unix(100, 0)
56		-	trace := newStartupTrace(func() time.Time { return now })
	84	+	trace := newStartupTrace(func() time.Time { return now }, now)
57	85
58	86		for _, name := range startupMilestoneOrder[:len(startupMilestoneOrder)-1] {
59	87		now = now.Add(time.Millisecond)
60	88		require.True(t, trace.Mark(name))
61	89		}
62	90
63		-	trace.Finish() // Legacy callers do not observe the upstream GTK after-paint.
64	91		require.Len(t, trace.milestones, len(startupMilestoneOrder)-1)
65		-	require.False(t, trace.Mark("first_gtk_presentation"), "generic callers cannot record the reserved milestone")
	92	+	require.False(t, trace.Mark("first_gtk_presentation"), "only the CEF-to-GTK after-paint hook can record the reserved milestone")
66	93		require.False(t, trace.summaryEmitted)
67	94		require.True(t, trace.MarkGTKAfterPaint(), "only the after-paint hook may record this milestone")
68	95		}

@@ -71,7 +98,7 @@ func TestStartupTraceEmitsOneNormalSummaryAtFirstPresentation(t *testing.T) {
71	98		var output bytes.Buffer
72	99		logger := zerolog.New(&output)
73	100		now := time.Unix(100, 0)
74		-	trace := newStartupTrace(func() time.Time { return now })
	101	+	trace := newStartupTrace(func() time.Time { return now }, now)
75	102		trace.SetBackend("gdk-dmabuf")
76	103		trace.SetLogger(&logger)
77	104

-package logging
+package cef
 import (
 	"bytes"
 	"github.com/stretchr/testify/require"
 )
+func TestActivateStartupTraceSeedsNeutralProcessAndConfigTiming(t *testing.T) {
+	processStartupTrace.Lock()
+	previous := processStartupTrace.trace
+	processStartupTrace.trace = nil
+	processStartupTrace.Unlock()
+	t.Cleanup(func() {
+		processStartupTrace.Lock()
+		processStartupTrace.trace = previous
+		processStartupTrace.Unlock()
+	})
+	processEntry := time.Unix(100, 0)
+	configComplete := processEntry.Add(15 * time.Millisecond)
+	var output bytes.Buffer
+	logger := zerolog.New(&output).Level(zerolog.DebugLevel)
+	ActivateStartupTrace(processEntry, configComplete, &logger)
+	trace := activeStartupTrace()
+	require.NotNil(t, trace)
+	require.Equal(t, []string{"process_entry", "config_complete"}, []string{trace.milestones[0].Name, trace.milestones[1].Name})
+	require.Equal(t, int64(0), trace.milestones[0].Elapsed.Milliseconds())
+	require.Equal(t, int64(15), trace.milestones[1].Elapsed.Milliseconds())
+	require.Contains(t, output.String(), `"milestone":"process_entry"`)
+	require.Contains(t, output.String(), `"milestone":"config_complete"`)
+	require.NotContains(t, output.String(), `"message":"startup_trace: first presentation"`)
+}
 func TestStartupTraceAcceptsOnlyOrderedOneShotMilestones(t *testing.T) {
 	now := time.Unix(100, 0)
-	trace := newStartupTrace(func() time.Time { return now })
+	trace := newStartupTrace(func() time.Time { return now }, now)
 	require.True(t, trace.Mark("process_entry"))
 	require.False(t, trace.Mark("cef_initialized"), "out-of-order transition must be rejected")
 	require.False(t, trace.Mark("first_gtk_presentation"))
 }
-func TestStartupTraceQuantizesDeltaToPublishedMilliseconds(t *testing.T) {
+func TestStartupTracePreservesProcessAndConfigTimestamps(t *testing.T) {
-	now := time.Unix(100, 0)
+	processEntry := time.Unix(100, 0)
-	trace := newStartupTrace(func() time.Time { return now })
+	configComplete := processEntry.Add(1500 * time.Microsecond)
+	now := configComplete.Add(900 * time.Microsecond)
+	trace := newStartupTrace(func() time.Time { return now }, processEntry)
-	now = now.Add(1500 * time.Microsecond)
+	require.True(t, trace.markAt("process_entry", processEntry))
-	require.True(t, trace.Mark("process_entry"))
+	require.True(t, trace.markAt("config_complete", configComplete))
-	now = now.Add(900 * time.Microsecond)
-	require.True(t, trace.Mark("config_complete"))
-	require.Equal(t, int64(1), trace.milestones[0].Elapsed.Milliseconds())
+	require.Equal(t, int64(0), trace.milestones[0].Elapsed.Milliseconds())
-	require.Equal(t, int64(1), trace.milestones[0].Delta.Milliseconds())
+	require.Equal(t, int64(0), trace.milestones[0].Delta.Milliseconds())
-	require.Equal(t, int64(2), trace.milestones[1].Elapsed.Milliseconds())
+	require.Equal(t, int64(1), trace.milestones[1].Elapsed.Milliseconds())
 	require.Equal(t, int64(1), trace.milestones[1].Delta.Milliseconds())
 }
-func TestStartupTraceFinishCannotFabricateFirstGTKPresentation(t *testing.T) {
+func TestStartupTraceReservesFirstGTKPresentationForAfterPaint(t *testing.T) {
 	now := time.Unix(100, 0)
-	trace := newStartupTrace(func() time.Time { return now })
+	trace := newStartupTrace(func() time.Time { return now }, now)
 	for _, name := range startupMilestoneOrder[:len(startupMilestoneOrder)-1] {
 		now = now.Add(time.Millisecond)
 		require.True(t, trace.Mark(name))
 	}
-	trace.Finish() // Legacy callers do not observe the upstream GTK after-paint.
 	require.Len(t, trace.milestones, len(startupMilestoneOrder)-1)
-	require.False(t, trace.Mark("first_gtk_presentation"), "generic callers cannot record the reserved milestone")
+	require.False(t, trace.Mark("first_gtk_presentation"), "only the CEF-to-GTK after-paint hook can record the reserved milestone")
 	require.False(t, trace.summaryEmitted)
 	require.True(t, trace.MarkGTKAfterPaint(), "only the after-paint hook may record this milestone")
 }
 	var output bytes.Buffer
 	logger := zerolog.New(&output)
 	now := time.Unix(100, 0)
-	trace := newStartupTrace(func() time.Time { return now })
+	trace := newStartupTrace(func() time.Time { return now }, now)
 	trace.SetBackend("gdk-dmabuf")
 	trace.SetLogger(&logger)

M internal/infrastructure/webkit/engine_init.go +0 -7


@@ -40,7 +40,6 @@ func NewEngine(
40	40
41	41		// --- Configure rendering environment (must be before GTK/WebKit init) ---
42	42		engineConfigureRenderingEnvironment(ctx, cfg, wkCfg, &perfSettings, logger)
43		-	logging.Trace().Mark("render_env")
44	43
45	44		// --- Build webKitContextOptions from opts + wkCfg + perfSettings ---
46	45		wkOpts := engineBuildContextOptions(opts, profile, wkCfg, &perfSettings)

@@ -53,7 +52,6 @@ func NewEngine(
53	52		if err != nil {
54	53		return nil, err
55	54		}
56		-	logging.Trace().Mark("webkit_context")
57	55
58	56		// --- Filter manager ---
59	57		filterManager := engineInitFilterManager(ctx, cfg, profile.Shared.DataDir, logger)

@@ -77,7 +75,6 @@ func NewEngine(
77	75		}
78	76
79	77		messageRouter := NewMessageRouter(ctx)
80		-	logging.Trace().Mark("settings_manager")
81	78
82	79		// --- WebView pool ---
83	80		poolCfg := DefaultPoolConfig()

@@ -100,7 +97,6 @@ func NewEngine(
100	97		} else {
101	98		logger.Warn().Msg("skipping first webview prewarm: no GDK display available yet")
102	99		}
103		-	logging.Trace().Mark("pool_prewarm_first")
104	100
105	101		// --- WebView factory ---
106	102		factory := NewWebViewFactory(wkCtx, settings, pool, injector, messageRouter)

@@ -147,7 +143,6 @@ func engineSurveyHardwareAndResolveProfile(
147	143		) config.ResolvedPerformanceSettings {
148	144		hwSurveyor := env.NewHardwareSurveyor()
149	145		hwInfo := hwSurveyor.Survey(ctx)
150		-	logging.Trace().Mark("hardware_survey")
151	146		logger.Info().
152	147		Int("cpu_cores", hwInfo.CPUCores).
153	148		Int("cpu_threads", hwInfo.CPUThreads).

@@ -158,7 +153,6 @@ func engineSurveyHardwareAndResolveProfile(
158	153
159	154		perfCfg := config.PerformanceConfigFromEngine(&cfg.Engine)
160	155		perfSettings := config.ResolvePerformanceProfile(&perfCfg, &hwInfo)
161		-	logging.Trace().Mark("performance_profile")
162	156		logger.Info().
163	157		Str("profile", string(cfg.Engine.Profile)).
164	158		Int("skia_cpu_threads", perfSettings.SkiaCPUPaintingThreads).

@@ -284,7 +278,6 @@ func engineInitFilterManager(ctx context.Context, cfg *config.Config, dataDir st
284	278		if err := filterManager.Initialize(ctx); err != nil {
285	279		logger.Warn().Err(err).Msg("failed to initialize filters, will load async")
286	280		}
287		-	logging.Trace().Mark("filter_manager")
288	281		return filterManager
289	282		}
290	283


@@ -40,7 +40,6 @@ func NewEngine(
40			40
41		// --- Configure rendering environment (must be before GTK/WebKit init) ---	41	// --- Configure rendering environment (must be before GTK/WebKit init) ---
42		engineConfigureRenderingEnvironment(ctx, cfg, wkCfg, &perfSettings, logger)	42	engineConfigureRenderingEnvironment(ctx, cfg, wkCfg, &perfSettings, logger)
43	-	logging.Trace().Mark("render_env")
44			43
45		// --- Build webKitContextOptions from opts + wkCfg + perfSettings ---	44	// --- Build webKitContextOptions from opts + wkCfg + perfSettings ---
46		wkOpts := engineBuildContextOptions(opts, profile, wkCfg, &perfSettings)	45	wkOpts := engineBuildContextOptions(opts, profile, wkCfg, &perfSettings)

@@ -53,7 +52,6 @@ func NewEngine(
53		if err != nil {	52	if err != nil {
54		return nil, err	53	return nil, err
55		}	54	}
56	-	logging.Trace().Mark("webkit_context")
57			55
58		// --- Filter manager ---	56	// --- Filter manager ---
59		filterManager := engineInitFilterManager(ctx, cfg, profile.Shared.DataDir, logger)	57	filterManager := engineInitFilterManager(ctx, cfg, profile.Shared.DataDir, logger)

@@ -77,7 +75,6 @@ func NewEngine(
77		}	75	}
78			76
79		messageRouter := NewMessageRouter(ctx)	77	messageRouter := NewMessageRouter(ctx)
80	-	logging.Trace().Mark("settings_manager")
81			78
82		// --- WebView pool ---	79	// --- WebView pool ---
83		poolCfg := DefaultPoolConfig()	80	poolCfg := DefaultPoolConfig()

@@ -100,7 +97,6 @@ func NewEngine(
100		} else {	97	} else {
101		logger.Warn().Msg("skipping first webview prewarm: no GDK display available yet")	98	logger.Warn().Msg("skipping first webview prewarm: no GDK display available yet")
102		}	99	}
103	-	logging.Trace().Mark("pool_prewarm_first")
104			100
105		// --- WebView factory ---	101	// --- WebView factory ---
106		factory := NewWebViewFactory(wkCtx, settings, pool, injector, messageRouter)	102	factory := NewWebViewFactory(wkCtx, settings, pool, injector, messageRouter)

@@ -147,7 +143,6 @@ func engineSurveyHardwareAndResolveProfile(
147		) config.ResolvedPerformanceSettings {	143	) config.ResolvedPerformanceSettings {
148		hwSurveyor := env.NewHardwareSurveyor()	144	hwSurveyor := env.NewHardwareSurveyor()
149		hwInfo := hwSurveyor.Survey(ctx)	145	hwInfo := hwSurveyor.Survey(ctx)
150	-	logging.Trace().Mark("hardware_survey")
151		logger.Info().	146	logger.Info().
152		Int("cpu_cores", hwInfo.CPUCores).	147	Int("cpu_cores", hwInfo.CPUCores).
153		Int("cpu_threads", hwInfo.CPUThreads).	148	Int("cpu_threads", hwInfo.CPUThreads).

@@ -158,7 +153,6 @@ func engineSurveyHardwareAndResolveProfile(
158			153
159		perfCfg := config.PerformanceConfigFromEngine(&cfg.Engine)	154	perfCfg := config.PerformanceConfigFromEngine(&cfg.Engine)
160		perfSettings := config.ResolvePerformanceProfile(&perfCfg, &hwInfo)	155	perfSettings := config.ResolvePerformanceProfile(&perfCfg, &hwInfo)
161	-	logging.Trace().Mark("performance_profile")
162		logger.Info().	156	logger.Info().
163		Str("profile", string(cfg.Engine.Profile)).	157	Str("profile", string(cfg.Engine.Profile)).
164		Int("skia_cpu_threads", perfSettings.SkiaCPUPaintingThreads).	158	Int("skia_cpu_threads", perfSettings.SkiaCPUPaintingThreads).

@@ -284,7 +278,6 @@ func engineInitFilterManager(ctx context.Context, cfg *config.Config, dataDir st
284		if err := filterManager.Initialize(ctx); err != nil {	278	if err := filterManager.Initialize(ctx); err != nil {
285		logger.Warn().Err(err).Msg("failed to initialize filters, will load async")	279	logger.Warn().Err(err).Msg("failed to initialize filters, will load async")
286		}	280	}
287	-	logging.Trace().Mark("filter_manager")
288		return filterManager	281	return filterManager
289		}	282	}
290			283

D internal/logging/startup_trace.go +0 -208

@@ -1,208 +0,0 @@
1	-	package logging
2	-
3	-	import (
4	-	"sync"
5	-	"time"
6	-
7	-	"github.com/rs/zerolog"
8	-	)
9	-
10	-	// StartupTrace records the single truthful path from process entry to the first
11	-	// GTK presentation. It deliberately rejects unknown, duplicate, and out of
12	-	// order milestones: accepting a convenient timestamp would make the result
13	-	// unsuitable for cold-start measurement.
14	-	type StartupTrace struct {
15	-	mu sync.Mutex
16	-	now func() time.Time
17	-	t0 time.Time
18	-	milestones []Milestone
19	-	logger *zerolog.Logger
20	-	buffered []Milestone
21	-	backend string
22	-	incompleteReason string
23	-	summaryEmitted bool
24	-	}
25	-
26	-	// Milestone represents a timing checkpoint measured from process entry.
27	-	type Milestone struct {
28	-	Name string
29	-	Elapsed time.Duration
30	-	Delta time.Duration
31	-	}
32	-
33	-	var startupMilestoneOrder = []string{
34	-	"process_entry",
35	-	"config_complete",
36	-	"cef_library_load_begin",
37	-	"cef_initialized",
38	-	"browser_create_requested",
39	-	"first_accelerated_paint_received",
40	-	"first_dmabuf_texture_swap",
41	-	"first_gtk_presentation",
42	-	}
43	-
44	-	var (
45	-	globalTrace *StartupTrace
46	-	globalTraceMu sync.Mutex
47	-	globalTraceOnce sync.Once
48	-	)
49	-
50	-	func newStartupTrace(now func() time.Time) *StartupTrace {
51	-	start := now()
52	-	return &StartupTrace{
53	-	now: now,
54	-	t0: start,
55	-	milestones: make([]Milestone, 0, len(startupMilestoneOrder)),
56	-	buffered: make([]Milestone, 0, len(startupMilestoneOrder)),
57	-	}
58	-	}
59	-
60	-	// InitStartupTrace must be called at the first instruction in main. logLevel is
61	-	// retained for source compatibility; this measurement is always collected so
62	-	// its final structured summary is available at normal log level.
63	-	func InitStartupTrace(_ string) {
64	-	globalTraceOnce.Do(func() {
65	-	trace := newStartupTrace(time.Now)
66	-	globalTraceMu.Lock()
67	-	globalTrace = trace
68	-	globalTraceMu.Unlock()
69	-	})
70	-	}
71	-
72	-	// Trace returns the process startup trace. Callers before initialization get a
73	-	// harmless trace which rejects all transitions.
74	-	func Trace() *StartupTrace {
75	-	globalTraceMu.Lock()
76	-	defer globalTraceMu.Unlock()
77	-	if globalTrace == nil {
78	-	return &StartupTrace{}
79	-	}
80	-	return globalTrace
81	-	}
82	-
83	-	// SetLogger makes buffered milestones available to the process logger.
84	-	func (st StartupTrace) SetLogger(logger zerolog.Logger) {
85	-	if st == nil \|\| logger == nil {
86	-	return
87	-	}
88	-	st.mu.Lock()
89	-	defer st.mu.Unlock()
90	-	st.logger = logger
91	-	for _, milestone := range st.buffered {
92	-	st.emitMilestone(milestone)
93	-	}
94	-	st.buffered = nil
95	-	st.emitSummaryLocked()
96	-	}
97	-
98	-	// UpdateLogger switches the destination without replaying events. Replaying
99	-	// would violate the one-shot property in session logs.
100	-	func (st StartupTrace) UpdateLogger(logger zerolog.Logger) { st.SetLogger(logger) }
101	-
102	-	// SetBackend records the selected presentation backend for the final summary.
103	-	func (st *StartupTrace) SetBackend(backend string) {
104	-	if st == nil {
105	-	return
106	-	}
107	-	st.mu.Lock()
108	-	defer st.mu.Unlock()
109	-	st.backend = backend
110	-	}
111	-
112	-	// SetIncompleteReason records why a trace cannot reach a valid DMABUF result.
113	-	func (st *StartupTrace) SetIncompleteReason(reason string) {
114	-	if st == nil {
115	-	return
116	-	}
117	-	st.mu.Lock()
118	-	defer st.mu.Unlock()
119	-	if st.incompleteReason == "" {
120	-	st.incompleteReason = reason
121	-	}
122	-	}
123	-
124	-	// Mark accepts exactly the next non-presentation startup milestone and returns
125	-	// whether it was recorded. first_gtk_presentation is reserved for the GTK
126	-	// frame-clock after-paint hook through MarkGTKAfterPaint.
127	-	func (st *StartupTrace) Mark(name string) bool {
128	-	if name == "first_gtk_presentation" {
129	-	return false
130	-	}
131	-	return st.mark(name)
132	-	}
133	-
134	-	// MarkGTKAfterPaint records the final milestone. It is called only from the
135	-	// upstream CEF-to-GTK bridge's first frame-clock after-paint callback.
136	-	func (st *StartupTrace) MarkGTKAfterPaint() bool {
137	-	return st.mark("first_gtk_presentation")
138	-	}
139	-
140	-	// mark accepts the next milestone and is safe for callbacks from CEF and GTK
141	-	// threads.
142	-	func (st *StartupTrace) mark(name string) bool {
143	-	if st == nil \|\| st.now == nil {
144	-	return false
145	-	}
146	-	st.mu.Lock()
147	-	defer st.mu.Unlock()
148	-	if len(st.milestones) >= len(startupMilestoneOrder) \|\| name != startupMilestoneOrder[len(st.milestones)] {
149	-	return false
150	-	}
151	-
152	-	now := st.now()
153	-	milestone := Milestone{Name: name, Elapsed: now.Sub(st.t0)}
154	-	// Published fields are integer milliseconds. Compute delta on that same
155	-	// scale so delta_ms always exactly reconstructs t_ms in collected evidence.
156	-	previousMilliseconds := int64(0)
157	-	if len(st.milestones) > 0 {
158	-	previousMilliseconds = st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()
159	-	}
160	-	milestone.Delta = time.Duration(milestone.Elapsed.Milliseconds()-previousMilliseconds) * time.Millisecond
161	-	st.milestones = append(st.milestones, milestone)
162	-	if st.logger == nil {
163	-	st.buffered = append(st.buffered, milestone)
164	-	} else {
165	-	st.emitMilestone(milestone)
166	-	}
167	-	st.emitSummaryLocked()
168	-	return true
169	-	}
170	-
171	-	func (st *StartupTrace) emitMilestone(m Milestone) {
172	-	if st.logger == nil {
173	-	return
174	-	}
175	-	st.logger.Debug().
176	-	Str("milestone", m.Name).
177	-	Int64("t_ms", m.Elapsed.Milliseconds()).
178	-	Int64("delta_ms", m.Delta.Milliseconds()).
179	-	Msg("startup_trace: milestone")
180	-	}
181	-
182	-	func (st *StartupTrace) emitSummaryLocked() {
183	-	if st.summaryEmitted \|\| st.logger == nil \|\| len(st.milestones) != len(startupMilestoneOrder) {
184	-	return
185	-	}
186	-	st.summaryEmitted = true
187	-	st.logger.Info().
188	-	Str("backend", st.backend).
189	-	Str("incomplete_reason", st.incompleteReason).
190	-	Int64("total_ms", st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()).
191	-	Interface("milestones", st.milestones).
192	-	Msg("startup_trace: first presentation")
193	-	}
194	-
195	-	// Finish is retained as a harmless compatibility no-op. The only valid source
196	-	// for first_gtk_presentation is the upstream GTK frame-clock after-paint hook.
197	-	func (*StartupTrace) Finish() {}
198	-
199	-	func (st *StartupTrace) Enabled() bool { return st != nil && st.now != nil }
200	-
201	-	func (st *StartupTrace) TotalElapsed() time.Duration {
202	-	if st == nil \|\| st.now == nil {
203	-	return 0
204	-	}
205	-	st.mu.Lock()
206	-	defer st.mu.Unlock()
207	-	return st.now().Sub(st.t0)
208	-	}

@@ -1,208 +0,0 @@
1	-	package logging
2	-
3	-	import (
4	-	"sync"
5	-	"time"
6	-
7	-	"github.com/rs/zerolog"
8	-	)
9	-
10	-	// StartupTrace records the single truthful path from process entry to the first
11	-	// GTK presentation. It deliberately rejects unknown, duplicate, and out of
12	-	// order milestones: accepting a convenient timestamp would make the result
13	-	// unsuitable for cold-start measurement.
14	-	type StartupTrace struct {
15	-	mu sync.Mutex
16	-	now func() time.Time
17	-	t0 time.Time
18	-	milestones []Milestone
19	-	logger *zerolog.Logger
20	-	buffered []Milestone
21	-	backend string
22	-	incompleteReason string
23	-	summaryEmitted bool
24	-	}
25	-
26	-	// Milestone represents a timing checkpoint measured from process entry.
27	-	type Milestone struct {
28	-	Name string
29	-	Elapsed time.Duration
30	-	Delta time.Duration
31	-	}
32	-
33	-	var startupMilestoneOrder = []string{
34	-	"process_entry",
35	-	"config_complete",
36	-	"cef_library_load_begin",
37	-	"cef_initialized",
38	-	"browser_create_requested",
39	-	"first_accelerated_paint_received",
40	-	"first_dmabuf_texture_swap",
41	-	"first_gtk_presentation",
42	-	}
43	-
44	-	var (
45	-	globalTrace *StartupTrace
46	-	globalTraceMu sync.Mutex
47	-	globalTraceOnce sync.Once
48	-	)
49	-
50	-	func newStartupTrace(now func() time.Time) *StartupTrace {
51	-	start := now()
52	-	return &StartupTrace{
53	-	now: now,
54	-	t0: start,
55	-	milestones: make([]Milestone, 0, len(startupMilestoneOrder)),
56	-	buffered: make([]Milestone, 0, len(startupMilestoneOrder)),
57	-	}
58	-	}
59	-
60	-	// InitStartupTrace must be called at the first instruction in main. logLevel is
61	-	// retained for source compatibility; this measurement is always collected so
62	-	// its final structured summary is available at normal log level.
63	-	func InitStartupTrace(_ string) {
64	-	globalTraceOnce.Do(func() {
65	-	trace := newStartupTrace(time.Now)
66	-	globalTraceMu.Lock()
67	-	globalTrace = trace
68	-	globalTraceMu.Unlock()
69	-	})
70	-	}
71	-
72	-	// Trace returns the process startup trace. Callers before initialization get a
73	-	// harmless trace which rejects all transitions.
74	-	func Trace() *StartupTrace {
75	-	globalTraceMu.Lock()
76	-	defer globalTraceMu.Unlock()
77	-	if globalTrace == nil {
78	-	return &StartupTrace{}
79	-	}
80	-	return globalTrace
81	-	}
82	-
83	-	// SetLogger makes buffered milestones available to the process logger.
84	-	func (st StartupTrace) SetLogger(logger zerolog.Logger) {
85	-	if st == nil \|\| logger == nil {
86	-	return
87	-	}
88	-	st.mu.Lock()
89	-	defer st.mu.Unlock()
90	-	st.logger = logger
91	-	for _, milestone := range st.buffered {
92	-	st.emitMilestone(milestone)
93	-	}
94	-	st.buffered = nil
95	-	st.emitSummaryLocked()
96	-	}
97	-
98	-	// UpdateLogger switches the destination without replaying events. Replaying
99	-	// would violate the one-shot property in session logs.
100	-	func (st StartupTrace) UpdateLogger(logger zerolog.Logger) { st.SetLogger(logger) }
101	-
102	-	// SetBackend records the selected presentation backend for the final summary.
103	-	func (st *StartupTrace) SetBackend(backend string) {
104	-	if st == nil {
105	-	return
106	-	}
107	-	st.mu.Lock()
108	-	defer st.mu.Unlock()
109	-	st.backend = backend
110	-	}
111	-
112	-	// SetIncompleteReason records why a trace cannot reach a valid DMABUF result.
113	-	func (st *StartupTrace) SetIncompleteReason(reason string) {
114	-	if st == nil {
115	-	return
116	-	}
117	-	st.mu.Lock()
118	-	defer st.mu.Unlock()
119	-	if st.incompleteReason == "" {
120	-	st.incompleteReason = reason
121	-	}
122	-	}
123	-
124	-	// Mark accepts exactly the next non-presentation startup milestone and returns
125	-	// whether it was recorded. first_gtk_presentation is reserved for the GTK
126	-	// frame-clock after-paint hook through MarkGTKAfterPaint.
127	-	func (st *StartupTrace) Mark(name string) bool {
128	-	if name == "first_gtk_presentation" {
129	-	return false
130	-	}
131	-	return st.mark(name)
132	-	}
133	-
134	-	// MarkGTKAfterPaint records the final milestone. It is called only from the
135	-	// upstream CEF-to-GTK bridge's first frame-clock after-paint callback.
136	-	func (st *StartupTrace) MarkGTKAfterPaint() bool {
137	-	return st.mark("first_gtk_presentation")
138	-	}
139	-
140	-	// mark accepts the next milestone and is safe for callbacks from CEF and GTK
141	-	// threads.
142	-	func (st *StartupTrace) mark(name string) bool {
143	-	if st == nil \|\| st.now == nil {
144	-	return false
145	-	}
146	-	st.mu.Lock()
147	-	defer st.mu.Unlock()
148	-	if len(st.milestones) >= len(startupMilestoneOrder) \|\| name != startupMilestoneOrder[len(st.milestones)] {
149	-	return false
150	-	}
151	-
152	-	now := st.now()
153	-	milestone := Milestone{Name: name, Elapsed: now.Sub(st.t0)}
154	-	// Published fields are integer milliseconds. Compute delta on that same
155	-	// scale so delta_ms always exactly reconstructs t_ms in collected evidence.
156	-	previousMilliseconds := int64(0)
157	-	if len(st.milestones) > 0 {
158	-	previousMilliseconds = st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()
159	-	}
160	-	milestone.Delta = time.Duration(milestone.Elapsed.Milliseconds()-previousMilliseconds) * time.Millisecond
161	-	st.milestones = append(st.milestones, milestone)
162	-	if st.logger == nil {
163	-	st.buffered = append(st.buffered, milestone)
164	-	} else {
165	-	st.emitMilestone(milestone)
166	-	}
167	-	st.emitSummaryLocked()
168	-	return true
169	-	}
170	-
171	-	func (st *StartupTrace) emitMilestone(m Milestone) {
172	-	if st.logger == nil {
173	-	return
174	-	}
175	-	st.logger.Debug().
176	-	Str("milestone", m.Name).
177	-	Int64("t_ms", m.Elapsed.Milliseconds()).
178	-	Int64("delta_ms", m.Delta.Milliseconds()).
179	-	Msg("startup_trace: milestone")
180	-	}
181	-
182	-	func (st *StartupTrace) emitSummaryLocked() {
183	-	if st.summaryEmitted \|\| st.logger == nil \|\| len(st.milestones) != len(startupMilestoneOrder) {
184	-	return
185	-	}
186	-	st.summaryEmitted = true
187	-	st.logger.Info().
188	-	Str("backend", st.backend).
189	-	Str("incomplete_reason", st.incompleteReason).
190	-	Int64("total_ms", st.milestones[len(st.milestones)-1].Elapsed.Milliseconds()).
191	-	Interface("milestones", st.milestones).
192	-	Msg("startup_trace: first presentation")
193	-	}
194	-
195	-	// Finish is retained as a harmless compatibility no-op. The only valid source
196	-	// for first_gtk_presentation is the upstream GTK frame-clock after-paint hook.
197	-	func (*StartupTrace) Finish() {}
198	-
199	-	func (st *StartupTrace) Enabled() bool { return st != nil && st.now != nil }
200	-
201	-	func (st *StartupTrace) TotalElapsed() time.Duration {
202	-	if st == nil \|\| st.now == nil {
203	-	return 0
204	-	}
205	-	st.mu.Lock()
206	-	defer st.mu.Unlock()
207	-	return st.now().Sub(st.t0)
208	-	}

M internal/ui/app.go +0 -4


@@ -295,7 +295,6 @@ func (a *App) Run(ctx context.Context, args []string) int {
295	295		// Initialize libadwaita once (required before using StyleManager).
296	296		// This also initializes GTK implicitly.
297	297		EnsureAdwaitaInitialized()
298		-	logging.Trace().Mark("gtk_init")
299	298
300	299		// Mark adwaita detector as available now that adw.Init() is complete.
301	300		// This enables the highest-priority color scheme detector.

@@ -317,7 +316,6 @@ func (a *App) Run(ctx context.Context, args []string) int {
317	316		return 1
318	317		}
319	318		defer a.gtkApp.Unref()
320		-	logging.Trace().Mark("gtk_app_created")
321	319		a.dispatchOnMainThread = a.runOnMainThread
322	320
323	321		// Connect activate signal

@@ -353,7 +351,6 @@ func (a *App) onActivate(ctx context.Context) {
353	351		log.Error().Err(err).Msg("failed to create main window")
354	352		return
355	353		}
356		-	logging.Trace().Mark("window_created")
357	354
358	355		a.installCrashReportNotifier(ctx)
359	356		a.initFocusManager()

@@ -362,7 +359,6 @@ func (a *App) onActivate(ctx context.Context) {
362	359
363	360		a.initCoordinators(ctx)
364	361		a.wireWebRTCPermissionIndicator()
365		-	logging.Trace().Mark("coordinators_init")
366	362		a.initKeyboardHandler(ctx)
367	363		a.initOmniboxConfig(ctx)
368	364		a.initFindBarConfig(ctx)


@@ -295,7 +295,6 @@ func (a *App) Run(ctx context.Context, args []string) int {
295		// Initialize libadwaita once (required before using StyleManager).	295	// Initialize libadwaita once (required before using StyleManager).
296		// This also initializes GTK implicitly.	296	// This also initializes GTK implicitly.
297		EnsureAdwaitaInitialized()	297	EnsureAdwaitaInitialized()
298	-	logging.Trace().Mark("gtk_init")
299			298
300		// Mark adwaita detector as available now that adw.Init() is complete.	299	// Mark adwaita detector as available now that adw.Init() is complete.
301		// This enables the highest-priority color scheme detector.	300	// This enables the highest-priority color scheme detector.

@@ -317,7 +316,6 @@ func (a *App) Run(ctx context.Context, args []string) int {
317		return 1	316	return 1
318		}	317	}
319		defer a.gtkApp.Unref()	318	defer a.gtkApp.Unref()
320	-	logging.Trace().Mark("gtk_app_created")
321		a.dispatchOnMainThread = a.runOnMainThread	319	a.dispatchOnMainThread = a.runOnMainThread
322			320
323		// Connect activate signal	321	// Connect activate signal

@@ -353,7 +351,6 @@ func (a *App) onActivate(ctx context.Context) {
353		log.Error().Err(err).Msg("failed to create main window")	351	log.Error().Err(err).Msg("failed to create main window")
354		return	352	return
355		}	353	}
356	-	logging.Trace().Mark("window_created")
357			354
358		a.installCrashReportNotifier(ctx)	355	a.installCrashReportNotifier(ctx)
359		a.initFocusManager()	356	a.initFocusManager()

@@ -362,7 +359,6 @@ func (a *App) onActivate(ctx context.Context) {
362			359
363		a.initCoordinators(ctx)	360	a.initCoordinators(ctx)
364		a.wireWebRTCPermissionIndicator()	361	a.wireWebRTCPermissionIndicator()
365	-	logging.Trace().Mark("coordinators_init")
366		a.initKeyboardHandler(ctx)	362	a.initKeyboardHandler(ctx)
367		a.initOmniboxConfig(ctx)	363	a.initOmniboxConfig(ctx)
368		a.initFindBarConfig(ctx)	364	a.initFindBarConfig(ctx)

M internal/ui/coordinator/content/coordinator.go +0 -6


@@ -314,12 +314,6 @@ func (c *Coordinator) activePaneOverrideID() (entity.PaneID, bool) {
314	314		return c.activePaneOverride, true
315	315		}
316	316
317		-	func (c *Coordinator) webViewCount() int {
318		-	c.webViewsMu.RLock()
319		-	defer c.webViewsMu.RUnlock()
320		-	return len(c.webViews)
321		-	}
322		-
323	317		func (c *Coordinator) getWebViewLocked(paneID entity.PaneID) port.WebView {
324	318		c.webViewsMu.RLock()
325	319		defer c.webViewsMu.RUnlock()


@@ -314,12 +314,6 @@ func (c *Coordinator) activePaneOverrideID() (entity.PaneID, bool) {
314		return c.activePaneOverride, true	314	return c.activePaneOverride, true
315		}	315	}
316			316
317	-	func (c *Coordinator) webViewCount() int {
318	-	c.webViewsMu.RLock()
319	-	defer c.webViewsMu.RUnlock()
320	-	return len(c.webViews)
321	-	}
322	-
323		func (c *Coordinator) getWebViewLocked(paneID entity.PaneID) port.WebView {	317	func (c *Coordinator) getWebViewLocked(paneID entity.PaneID) port.WebView {
324		c.webViewsMu.RLock()	318	c.webViewsMu.RLock()
325		defer c.webViewsMu.RUnlock()	319	defer c.webViewsMu.RUnlock()

M internal/ui/coordinator/content/lifecycle.go +0 -7


@@ -28,16 +28,10 @@ func (c *Coordinator) EnsureWebView(ctx context.Context, paneID entity.PaneID) (
28	28		return nil, fmt.Errorf("webview pool not configured")
29	29		}
30	30
31		-	// Mark tab_created on first webview (first tab)
32		-	if c.webViewCount() == 0 {
33		-	logging.Trace().Mark("tab_created")
34		-	}
35		-
36	31		wv, err := c.pool.Acquire(ctx)
37	32		if err != nil {
38	33		return nil, err
39	34		}
40		-	logging.Trace().Mark("webview_acquired")
41	35
42	36		// setWebViewLocked atomically resets presentation state for the acquired
43	37		// WebView, including a pooled instance previously revealed in another pane.

@@ -144,7 +138,6 @@ func (c Coordinator) AttachToWorkspace(ctx context.Context, ws entity.Workspac
144	138		log.Warn().Err(err).Str("pane_id", string(pane.ID)).Msg("failed to attach webview widget")
145	139		continue
146	140		}
147		-	logging.Trace().Mark("webview_attached")
148	141		}
149	142		}
150	143


@@ -28,16 +28,10 @@ func (c *Coordinator) EnsureWebView(ctx context.Context, paneID entity.PaneID) (
28		return nil, fmt.Errorf("webview pool not configured")	28	return nil, fmt.Errorf("webview pool not configured")
29		}	29	}
30			30
31	-	// Mark tab_created on first webview (first tab)
32	-	if c.webViewCount() == 0 {
33	-	logging.Trace().Mark("tab_created")
34	-	}
35	-
36		wv, err := c.pool.Acquire(ctx)	31	wv, err := c.pool.Acquire(ctx)
37		if err != nil {	32	if err != nil {
38		return nil, err	33	return nil, err
39		}	34	}
40	-	logging.Trace().Mark("webview_acquired")
41			35
42		// setWebViewLocked atomically resets presentation state for the acquired	36	// setWebViewLocked atomically resets presentation state for the acquired
43		// WebView, including a pooled instance previously revealed in another pane.	37	// WebView, including a pooled instance previously revealed in another pane.

@@ -144,7 +138,6 @@ func (c Coordinator) AttachToWorkspace(ctx context.Context, ws entity.Workspac
144		log.Warn().Err(err).Str("pane_id", string(pane.ID)).Msg("failed to attach webview widget")	138	log.Warn().Err(err).Str("pane_id", string(pane.ID)).Msg("failed to attach webview widget")
145		continue	139	continue
146		}	140	}
147	-	logging.Trace().Mark("webview_attached")
148		}	141	}
149		}	142	}
150			143

M internal/ui/coordinator/content/navigation.go +0 -3


@@ -19,7 +19,6 @@ import (
19	19		// Also shows the WebView widget (it's hidden during creation to avoid white flash).
20	20		func (c *Coordinator) onLoadCommitted(ctx context.Context, paneID entity.PaneID, wv port.WebView, identity webViewIdentity) {
21	21		log := logging.FromContext(ctx)
22		-	logging.Trace().Mark("load_committed")
23	22
24	23		uri := wv.URI()
25	24		if uri == "" {

@@ -177,8 +176,6 @@ func (c *Coordinator) updatePaneURI(paneID entity.PaneID, uri string) {
177	176
178	177		// onLoadStarted shows the progress bar when page loading begins.
179	178		func (c *Coordinator) onLoadStarted(paneID entity.PaneID) {
180		-	logging.Trace().Mark("load_started")
181		-
182	179		// Trigger deferred initialization on first load_started.
183	180		// This ensures non-critical init runs after initial navigation starts.
184	181		c.loadStartedOnce.Do(func() {


@@ -19,7 +19,6 @@ import (
19		// Also shows the WebView widget (it's hidden during creation to avoid white flash).	19	// Also shows the WebView widget (it's hidden during creation to avoid white flash).
20		func (c *Coordinator) onLoadCommitted(ctx context.Context, paneID entity.PaneID, wv port.WebView, identity webViewIdentity) {	20	func (c *Coordinator) onLoadCommitted(ctx context.Context, paneID entity.PaneID, wv port.WebView, identity webViewIdentity) {
21		log := logging.FromContext(ctx)	21	log := logging.FromContext(ctx)
22	-	logging.Trace().Mark("load_committed")
23			22
24		uri := wv.URI()	23	uri := wv.URI()
25		if uri == "" {	24	if uri == "" {

@@ -177,8 +176,6 @@ func (c *Coordinator) updatePaneURI(paneID entity.PaneID, uri string) {
177			176
178		// onLoadStarted shows the progress bar when page loading begins.	177	// onLoadStarted shows the progress bar when page loading begins.
179		func (c *Coordinator) onLoadStarted(paneID entity.PaneID) {	178	func (c *Coordinator) onLoadStarted(paneID entity.PaneID) {
180	-	logging.Trace().Mark("load_started")
181	-
182		// Trigger deferred initialization on first load_started.	179	// Trigger deferred initialization on first load_started.
183		// This ensures non-critical init runs after initial navigation starts.	180	// This ensures non-critical init runs after initial navigation starts.
184		c.loadStartedOnce.Do(func() {	181	c.loadStartedOnce.Do(func() {