Merge remote-tracking branch 'origin/dev' into codex/headless-timing-output

go.mod

@@ -102,7 +102,7 @@ require (
 	github.com/projectdiscovery/tlsx v1.4.1
 	github.com/projectdiscovery/uncover v1.2.1
 	github.com/projectdiscovery/useragent v0.0.109
-	github.com/projectdiscovery/utils v0.11.9
+	github.com/projectdiscovery/utils v0.11.10-0.20261017183053-ac02d12acdf3
 	github.com/projectdiscovery/wappalyzergo v0.3.4
 	github.com/projectdiscovery/yamldoc-go v1.0.7
 	github.com/redis/go-redis/v9 v9.19.0

go.sum

@@ -1005,6 +1005,8 @@ github.com/projectdiscovery/useragent v0.0.109 h1:b86BPdZvmgbJousa04jAugDRY4Y+rA
 github.com/projectdiscovery/useragent v0.0.109/go.mod h1:sRyBqDAcD31RKYrO8fyXGowLd36fNwY1g0MNW9mp7zk=
 github.com/projectdiscovery/utils v0.11.9 h1:aKLje3zPcZuOGmopN51PasWxPX/CypPwzP2ke/Qa2bA=
 github.com/projectdiscovery/utils v0.11.9/go.mod h1:d3BcbsHhuxW9T3jpvrgzwshvqhaL9qPSkoi+3h/DY8E=
+github.com/projectdiscovery/utils v0.11.10-0.20261017183053-ac02d12acdf3 h1:TcGBnYp/RhcGGwNa6sP8/V/oJBDsbGnmBWU1yR0K/2U=
+github.com/projectdiscovery/utils v0.11.10-0.20261017183053-ac02d12acdf3/go.mod h1:d3BcbsHhuxW9T3jpvrgzwshvqhaL9qPSkoi+3h/DY8E=
 github.com/projectdiscovery/wappalyzergo v0.3.4 h1:yO+xel+C0d/vOFWcUKVZRpIDAfcEmsjpVDjQ0jifAUw=
 github.com/projectdiscovery/wappalyzergo v0.3.4/go.mod h1:6xTRCUQhX8m+L1eqJDQIALJlRv2Bnhrmku80YU9bBXE=
 github.com/projectdiscovery/yamldoc-go v1.0.7 h1:Odmjd1o4EkMff2F6QHi1dIYPIQPZUFy24YqmQCprmTk=

pkg/protocols/common/protocolstate/memguardian.go

@@ -5,6 +5,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/docker/go-units"
 	"github.com/projectdiscovery/gologger"
 	"github.com/projectdiscovery/utils/env"
 	httputil "github.com/projectdiscovery/utils/http"
@@ -16,6 +17,7 @@ var (
 	MaxBytesBufferAllocOnLowMemory = env.GetEnvOrDefault("MEMGUARDIAN_ALLOC", 0)
 	memTimer                       *time.Ticker
 	cancelFunc                     context.CancelFunc
+	memWatcherDone                 chan struct{}
 	muGlobalChange                 sync.Mutex
 )
 
@@ -25,12 +27,18 @@ func StartActiveMemGuardian(ctx context.Context) {
 	if memguardian.DefaultMemGuardian == nil || memTimer != nil {
 		return
 	}
+	if err := refreshMemoryWarning(); err != nil {
+		gologger.Warning().Msgf("could not check memory pressure: %s", err)
+	}
 
 	memTimer = time.NewTicker(memguardian.DefaultInterval)
 	ctx, cancelFunc = context.WithCancel(ctx)
+	memWatcherDone = make(chan struct{})
 
 	ticker := memTimer
+	done := memWatcherDone
 	go func(t *time.Ticker) {
+		defer close(done)
 		if t == nil {
 			return
 		}
@@ -39,6 +47,9 @@ func StartActiveMemGuardian(ctx context.Context) {
 			case <-ctx.Done():
 				return
 			case <-t.C:
+				if err := refreshMemoryWarning(); err != nil {
+					gologger.Warning().Msgf("could not check memory pressure: %s", err)
+				}
 				if IsLowOnMemory() {
 					_ = GlobalGuardBytesBufferAlloc()
 				} else {
@@ -49,6 +60,24 @@ func StartActiveMemGuardian(ctx context.Context) {
 	}(ticker)
 }
 
+func refreshMemoryWarning() error {
+	usedRatio, usedBytes, err := memguardian.UsedRam()
+	if err != nil {
+		return err
+	}
+
+	warning := usedRatio >= memguardian.DefaultMaxUsedRamRatio
+	if maxRam := env.GetEnvOrDefault(memguardian.MemGuardianMaxUsedMemoryENV, ""); maxRam != "" {
+		maxBytes, err := units.FromHumanSize(maxRam)
+		if err != nil {
+			return err
+		}
+		warning = warning || usedBytes >= uint64(maxBytes)
+	}
+	memguardian.DefaultMemGuardian.Warning.Store(warning)
+	return nil
+}
+
 func StopActiveMemGuardian() {
 	muGlobalChange.Lock()
 	defer muGlobalChange.Unlock()
@@ -61,6 +90,10 @@ func StopActiveMemGuardian() {
 		cancelFunc()
 		cancelFunc = nil
 	}
+	if memWatcherDone != nil {
+		<-memWatcherDone
+		memWatcherDone = nil
+	}
 	if memTimer != nil {
 		memTimer.Stop()
 		memTimer = nil

pkg/protocols/common/protocolstate/memguardian_test.go

@@ -127,3 +127,33 @@ func TestMemGuardianReset(t *testing.T) {
 	StopActiveMemGuardian()
 	time.Sleep(10 * time.Millisecond) // Allow cleanup
 }
+
+func TestActiveMemGuardianUpdatesLowMemoryWarning(t *testing.T) {
+	StopActiveMemGuardian()
+	t.Setenv(memguardian.MemGuardianMaxUsedMemoryENV, "")
+	original := memguardian.DefaultMemGuardian
+	originalInterval := memguardian.DefaultInterval
+	originalRatio := memguardian.DefaultMaxUsedRamRatio
+	memguardian.DefaultInterval = 5 * time.Millisecond
+	memguardian.DefaultMaxUsedRamRatio = 1
+	guardian, err := memguardian.New(
+		memguardian.WitInterval(memguardian.DefaultInterval),
+		memguardian.WithMaxRamRatioWarning(1),
+	)
+	require.NoError(t, err)
+	memguardian.DefaultMemGuardian = guardian
+	t.Cleanup(func() {
+		StopActiveMemGuardian()
+		guardian.Close()
+		memguardian.DefaultMemGuardian = original
+		memguardian.DefaultInterval = originalInterval
+		memguardian.DefaultMaxUsedRamRatio = originalRatio
+	})
+
+	StartActiveMemGuardian(context.Background())
+	require.Eventually(t, IsLowOnMemory, 100*time.Millisecond, 5*time.Millisecond)
+	StopActiveMemGuardian()
+	memguardian.DefaultMaxUsedRamRatio = 100
+	require.NoError(t, refreshMemoryWarning())
+	require.False(t, IsLowOnMemory())
+}

pkg/protocols/headless/engine/page.go

@@ -52,9 +52,10 @@ type HistoryData struct {
 
 // Options contains additional configuration options for the browser instance
 type Options struct {
-	Timeout       time.Duration
-	DisableCookie bool
-	Options       *types.Options
+	Timeout        time.Duration
+	DisableCookie  bool
+	Options        *types.Options
+	OnActionTiming func(ActionType, time.Duration)
 }
 
 // Run runs a list of actions by creating a new page in the browser.

pkg/protocols/headless/engine/page_actions.go

@@ -52,6 +52,7 @@ func (p *Page) ExecuteActions(input *contextargs.Context, actions []*Action) (ou
 
 	type deferredWaitFunc struct {
 		actionIndex int
+		actionType  ActionType
 		run         func() error
 	}
 
@@ -76,6 +77,7 @@ func (p *Page) ExecuteActions(input *contextargs.Context, actions []*Action) (ou
 		actionIndex := len(p.ActionDurations)
 		timeStart := time.Now()
 		var deferredWaitDuration time.Duration
+		deferredWaitFailed := false
 		switch act.ActionType.ActionType {
 		case ActionNavigate:
 			err = p.NavigateURL(act, outData)
@@ -84,18 +86,24 @@ func (p *Page) ExecuteActions(input *contextargs.Context, actions []*Action) (ou
 				for _, waitFunc := range waitFuncs {
 					if waitFunc.run != nil {
 						waitStart := time.Now()
-						if err := waitFunc.run(); err != nil {
-							waitDuration := time.Since(waitStart)
-							addActionDuration(p.ActionDurations, waitFunc.actionIndex, waitDuration)
-							return nil, errkit.Wrap(err, "error occurred while executing waitFunc")
-						}
+						waitErr := waitFunc.run()
 						waitDuration := time.Since(waitStart)
 						addActionDuration(p.ActionDurations, waitFunc.actionIndex, waitDuration)
+						if p.options.OnActionTiming != nil {
+							p.options.OnActionTiming(waitFunc.actionType, waitDuration)
+						}
 						deferredWaitDuration += waitDuration
+						if waitErr != nil {
+							err = waitErr
+							deferredWaitFailed = true
+							break
+						}
 					}
 				}
 
-				p.lastActionNavigate = act
+				if err == nil {
+					p.lastActionNavigate = act
+				}
 			}
 		case ActionScript:
 			err = p.RunScript(act, outData)
@@ -141,7 +149,7 @@ func (p *Page) ExecuteActions(input *contextargs.Context, actions []*Action) (ou
 			var waitFunc func() error
 			waitFunc, err = p.WaitEvent(act, outData)
 			if waitFunc != nil {
-				waitFuncs = append(waitFuncs, deferredWaitFunc{actionIndex: actionIndex, run: waitFunc})
+				waitFuncs = append(waitFuncs, deferredWaitFunc{actionIndex: actionIndex, actionType: act.ActionType.ActionType, run: waitFunc})
 			}
 		case ActionWaitDialog:
 			err = p.HandleDialog(act, outData)
@@ -177,11 +185,20 @@ func (p *Page) ExecuteActions(input *contextargs.Context, actions []*Action) (ou
 		default:
 			executed = false
 		}
-		if err != nil {
-			return nil, errors.Wrap(err, "error occurred executing action")
-		}
 		if executed {
-			p.ActionDurations = append(p.ActionDurations, max(time.Since(timeStart)-deferredWaitDuration, 0))
+			duration := max(time.Since(timeStart)-deferredWaitDuration, 0)
+			if p.options.OnActionTiming != nil {
+				p.options.OnActionTiming(act.ActionType.ActionType, duration)
+			}
+			if err == nil {
+				p.ActionDurations = append(p.ActionDurations, duration)
+			}
+		}
+		if err != nil {
+			if deferredWaitFailed {
+				return nil, errkit.Wrap(err, "error occurred while executing waitFunc")
+			}
+			return nil, errors.Wrap(err, "error occurred executing action")
 		}
 	}
 	return outData, nil
@@ -732,6 +749,18 @@ func (p *Page) SelectInputElement(act *Action, out ActionData) error {
 
 // WaitPageLifecycleEvent waits for specified page lifecycle event name
 func (p *Page) WaitPageLifecycleEvent(act *Action, out ActionData, event proto.PageLifecycleEventName) error {
+	if event == proto.PageLifecycleEventNameLoad {
+		dur, err := getTimeout(p, act)
+		if err != nil {
+			return err
+		}
+		if err := p.page.Timeout(dur).WaitLoad(); err != nil {
+			return err
+		}
+		p.updateLastNavigatedURL()
+		return nil
+	}
+
 	fn, err := getNavigationFunc(p, act, event)
 	if err != nil {
 		return err

pkg/protocols/headless/engine/page_actions_test.go

@@ -18,6 +18,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/go-rod/rod/lib/proto"
 	"github.com/stretchr/testify/require"
 
 	"github.com/projectdiscovery/nuclei/v3/internal/tests/testheadless"
@@ -642,6 +643,47 @@ func TestActionWaitLoad(t *testing.T) {
 	})
 }
 
+func TestActionWaitLoadAfterPageAlreadyLoaded(t *testing.T) {
+	actions := []*Action{{ActionType: ActionTypeHolder{ActionType: ActionNavigate}, Data: map[string]string{"url": "{{BaseURL}}"}}}
+	testHeadlessSimpleResponse(t, "<html><body>ready</body></html>", actions, 10*time.Second, func(page *Page, err error, _ ActionData) {
+		require.NoError(t, err)
+		require.NoError(t, page.Page().WaitLoad())
+
+		wait := &Action{ActionType: ActionTypeHolder{ActionType: ActionWaitLoad}, Data: map[string]string{"timeout": "2s"}}
+		started := time.Now()
+		require.NoError(t, page.WaitPageLifecycleEvent(wait, nil, proto.PageLifecycleEventNameLoad))
+		require.Less(t, time.Since(started), 1500*time.Millisecond, "a completed load must not consume the full wait timeout")
+	})
+}
+
+func TestActionWaitLoadWaitsForPendingResource(t *testing.T) {
+	resourceDone := make(chan struct{})
+	actions := []*Action{
+		{ActionType: ActionTypeHolder{ActionType: ActionNavigate}, Data: map[string]string{"url": "{{BaseURL}}"}},
+		{ActionType: ActionTypeHolder{ActionType: ActionWaitLoad}},
+	}
+	testHeadless(t, actions, 10*time.Second, func(w http.ResponseWriter, r *http.Request) {
+		if r.URL.Path == "/slow.js" {
+			w.Header().Set("Content-Type", "text/javascript")
+			time.Sleep(300 * time.Millisecond)
+			_, _ = fmt.Fprint(w, "window.resourceLoaded = true")
+			close(resourceDone)
+			return
+		}
+		_, _ = fmt.Fprint(w, `<html><script src="/slow.js"></script></html>`)
+	}, func(page *Page, err error, _ ActionData) {
+		require.NoError(t, err)
+		select {
+		case <-resourceDone:
+		default:
+			t.Fatal("waitload returned before the pending resource completed")
+		}
+		loaded, evalErr := page.Page().Eval(`() => window.resourceLoaded`)
+		require.NoError(t, evalErr)
+		require.True(t, loaded.Value.Bool())
+	})
+}
+
 func TestActionGetResource(t *testing.T) {
 	response := `
 		<html>
@@ -839,6 +881,25 @@ func TestActionWaitEventDuration(t *testing.T) {
 	})
 }
 
+func TestActionNavigateDurationIncludesResponseHeaderWait(t *testing.T) {
+	actions := []*Action{
+		{ActionType: ActionTypeHolder{ActionType: ActionNavigate}, Data: map[string]string{"url": "{{BaseURL}}"}},
+		{ActionType: ActionTypeHolder{ActionType: ActionWaitLoad}},
+	}
+
+	handler := func(w http.ResponseWriter, _ *http.Request) {
+		time.Sleep(350 * time.Millisecond)
+		_, _ = fmt.Fprintln(w, `<html><body>loaded</body></html>`)
+	}
+
+	testHeadless(t, actions, 20*time.Second, handler, func(page *Page, err error, _ ActionData) {
+		require.NoError(t, err)
+		require.Len(t, page.ActionDurations, 2)
+		require.GreaterOrEqual(t, page.ActionDurations[0], 300*time.Millisecond)
+		require.Less(t, page.ActionDurations[1], time.Second)
+	})
+}
+
 func TestActionWaitEventSeesEventFiredBeforeWaiting(t *testing.T) {
 	actions := []*Action{
 		{ActionType: ActionTypeHolder{ActionType: ActionNavigate}, Data: map[string]string{"url": "{{BaseURL}}"}},
@@ -1071,10 +1132,21 @@ func TestHeadlessRunHonorsParentCancellation(t *testing.T) {
 	}}
 
 	startedAt := time.Now()
-	_, page, err := instance.Run(input, actions, nil, &Options{Timeout: 5 * time.Second, Options: opts})
+	var timedAction ActionType
+	var timedDuration time.Duration
+	_, page, err := instance.Run(input, actions, nil, &Options{
+		Timeout: 5 * time.Second,
+		Options: opts,
+		OnActionTiming: func(action ActionType, duration time.Duration) {
+			timedAction = action
+			timedDuration = duration
+		},
+	})
 
 	require.ErrorIs(t, err, context.Canceled)
 	require.Nil(t, page)
+	require.Equal(t, ActionNavigate, timedAction)
+	require.Positive(t, timedDuration)
 	require.Less(t, time.Since(startedAt), 2*time.Second)
 }
 

pkg/protocols/headless/request.go

@@ -79,6 +79,10 @@ func (request *Request) ExecuteWithResults(input *contextargs.Context, metadata,
 	if len(request.Fuzzing) > 0 {
 		return request.executeFuzzingRule(input, vars, previous, wrappedCallback)
 	}
+	timing := newHeadlessTimingTrace(request.options.TemplateID, input.MetaInput.Input)
+	if timing != nil {
+		defer timing.emit(request.options.Logger)
+	}
 	if request.generator != nil {
 		iterator := request.generator.NewIterator()
 		for {
@@ -103,13 +107,13 @@ func (request *Request) ExecuteWithResults(input *contextargs.Context, metadata,
 				return errors.Wrap(err, "could not evaluate payload helper expressions")
 			}
 
-			if err := request.executeRequestWithPayloads(input, renderedValue.Values, previous, renderedValue.InteractURLs, wrappedCallback); err != nil {
+			if err := request.executeRequestWithPayloads(input, renderedValue.Values, previous, renderedValue.InteractURLs, wrappedCallback, timing); err != nil {
 				return err
 			}
 		}
 	} else {
 		value := maps.Clone(vars)
-		if err := request.executeRequestWithPayloads(input, value, previous, interactshURLs, wrappedCallback); err != nil {
+		if err := request.executeRequestWithPayloads(input, value, previous, interactshURLs, wrappedCallback, timing); err != nil {
 			return err
 		}
 	}
@@ -132,9 +136,15 @@ func extractBaseURLFromActions(steps []*engine.Action) (string, error) {
 	return "", errors.New("no navigation action found")
 }
 
-func (request *Request) executeRequestWithPayloads(input *contextargs.Context, payloads map[string]interface{}, previous output.InternalEvent, interactshURLs []string, callback protocols.OutputEventCallback) error {
+func (request *Request) executeRequestWithPayloads(input *contextargs.Context, payloads map[string]interface{}, previous output.InternalEvent, interactshURLs []string, callback protocols.OutputEventCallback, timing *headlessTimingTrace) error {
+	if timing != nil {
+		timing.attempts++
+	}
 	pageTimeout := time.Duration(request.options.Options.PageTimeout) * time.Second
 	if _, err := url.Parse(input.MetaInput.Input); err != nil {
+		if timing != nil {
+			timing.errors++
+		}
 		request.options.Output.Request(request.options.TemplatePath, input.MetaInput.Input, request.Type().String(), err)
 		request.options.Progress.IncrementFailedRequestsBy(1)
 		return errors.Wrap(err, errCouldNotGetHtmlElement)
@@ -144,35 +154,82 @@ func (request *Request) executeRequestWithPayloads(input *contextargs.Context, p
 		DisableCookie: request.DisableCookie,
 		Options:       request.options.Options,
 	}
+	var actionTimings []headlessActionTiming
+	if timing != nil {
+		options.OnActionTiming = func(action engine.ActionType, duration time.Duration) {
+			actionTimings = append(actionTimings, headlessActionTiming{action: action, duration: duration})
+		}
+	}
 
 	if !options.DisableCookie && input.CookieJar == nil {
+		if timing != nil {
+			timing.errors++
+		}
 		return errors.New("cookie reuse enabled but cookie-jar is nil")
 	}
 
 	// limited as one request per run of the steps, the unit progress counts
-	if err := request.options.RateLimitTakeContext(input.Context(), input.MetaInput.Input); err != nil {
-		request.options.Output.Request(request.options.TemplatePath, input.MetaInput.Input, request.Type().String(), err)
+	var rateWaitStarted time.Time
+	if timing != nil {
+		rateWaitStarted = time.Now()
+	}
+	rateWaitErr := request.options.RateLimitTakeContext(input.Context(), input.MetaInput.Input)
+	if timing != nil {
+		timing.rateWait += time.Since(rateWaitStarted)
+	}
+	if rateWaitErr != nil {
+		if timing != nil {
+			timing.errors++
+		}
+		request.options.Output.Request(request.options.TemplatePath, input.MetaInput.Input, request.Type().String(), rateWaitErr)
 		request.options.Progress.IncrementFailedRequestsBy(1)
-		return errors.Wrap(err, "could not take rate limit")
+		return errors.Wrap(rateWaitErr, "could not take rate limit")
 	}
 
+	var createStarted time.Time
+	if timing != nil {
+		createStarted = time.Now()
+	}
 	instance, err := request.options.Browser.NewInstanceWithContext(input.Context(), pageTimeout)
+	if timing != nil {
+		timing.contextCreate += time.Since(createStarted)
+	}
 	if err != nil {
+		if timing != nil {
+			timing.errors++
+		}
 		request.options.Output.Request(request.options.TemplatePath, input.MetaInput.Input, request.Type().String(), err)
 		request.options.Progress.IncrementFailedRequestsBy(1)
 		return errors.Wrap(err, errCouldNotGetHtmlElement)
 	}
 	var page *engine.Page
 	defer func() {
+		var cleanupStarted time.Time
+		if timing != nil {
+			cleanupStarted = time.Now()
+		}
 		if closeErr := instance.CloseWithPage(page); closeErr != nil {
 			gologger.Warning().Msgf("Could not close headless browser instance: %s", closeErr)
 		}
+		if timing != nil {
+			timing.cleanup += time.Since(cleanupStarted)
+		}
 	}()
 	instance.SetInteractsh(request.options.Interactsh)
 
 	timeStart := time.Now()
 	out, createdPage, err := instance.Run(input, request.Steps, payloads, options)
 	runDuration := time.Since(timeStart)
+	if timing != nil {
+		if err != nil {
+			timing.errors++
+			timing.recordFailedRun(actionTimings, runDuration)
+		} else if createdPage != nil {
+			timing.recordRun(request.Steps, createdPage.ActionDurations, runDuration)
+		} else {
+			timing.runOther += runDuration
+		}
+	}
 	if err != nil {
 		request.options.Output.Request(request.options.TemplatePath, input.MetaInput.Input, request.Type().String(), err)
 		request.options.Progress.IncrementFailedRequestsBy(1)
@@ -294,7 +351,7 @@ func (request *Request) executeFuzzingRule(input *contextargs.Context, payloads
 		newInput := input.Clone()
 		newInput.MetaInput.Input = gr.Request.String()
 
-		if err := request.executeRequestWithPayloads(newInput, gr.DynamicValues, previous, gr.InteractURLs, callback); err != nil {
+		if err := request.executeRequestWithPayloads(newInput, gr.DynamicValues, previous, gr.InteractURLs, callback, nil); err != nil {
 			return false
 		}
 

pkg/protocols/headless/timing.go

@@ -0,0 +1,141 @@
+package headless
+
+import (
+	"crypto/sha256"
+	"encoding/binary"
+	"fmt"
+	"os"
+	"strings"
+	"time"
+
+	"github.com/projectdiscovery/gologger"
+	"github.com/projectdiscovery/nuclei/v3/pkg/protocols/headless/engine"
+)
+
+const (
+	headlessTimingTemplatesEnv = "NUCLEI_HEADLESS_TIMING_TEMPLATES"
+	headlessTimingSampleRate   = 50
+	headlessTimingSampleMin    = 30 * time.Second
+	headlessTimingOutlierMin   = 5 * time.Minute
+)
+
+type headlessTimingTrace struct {
+	templateID        string
+	targetFingerprint string
+	sampled           bool
+	started           time.Time
+	attempts          int
+	errors            int
+	rateWait          time.Duration
+	contextCreate     time.Duration
+	navigate          time.Duration
+	waitLoad          time.Duration
+	waitDialog        time.Duration
+	otherActions      time.Duration
+	runOther          time.Duration
+	cleanup           time.Duration
+}
+
+type headlessActionTiming struct {
+	action   engine.ActionType
+	duration time.Duration
+}
+
+func newHeadlessTimingTrace(templateID, target string) *headlessTimingTrace {
+	selectedTemplates := os.Getenv(headlessTimingTemplatesEnv)
+	if selectedTemplates == "" {
+		return nil
+	}
+	selected := false
+	for _, candidate := range strings.Split(selectedTemplates, ",") {
+		if strings.TrimSpace(candidate) == templateID {
+			selected = true
+			break
+		}
+	}
+	if !selected {
+		return nil
+	}
+	fingerprint := sha256.Sum256([]byte(target))
+	return &headlessTimingTrace{
+		templateID:        templateID,
+		targetFingerprint: fmt.Sprintf("%x", fingerprint[:8]),
+		sampled:           binary.BigEndian.Uint64(fingerprint[:8])%headlessTimingSampleRate == 0,
+		started:           time.Now(),
+	}
+}
+
+func (t *headlessTimingTrace) recordRun(steps []*engine.Action, durations []time.Duration, elapsed time.Duration) {
+	actions := time.Duration(0)
+	if len(steps) != len(durations) {
+		for _, duration := range durations {
+			actions += duration
+		}
+		t.otherActions += actions
+		if elapsed > actions {
+			t.runOther += elapsed - actions
+		}
+		return
+	}
+	for index, duration := range durations {
+		actions += duration
+		if steps[index] == nil {
+			t.otherActions += duration
+			continue
+		}
+		switch steps[index].ActionType.ActionType {
+		case engine.ActionNavigate:
+			t.navigate += duration
+		case engine.ActionWaitLoad:
+			t.waitLoad += duration
+		case engine.ActionWaitDialog:
+			t.waitDialog += duration
+		default:
+			t.otherActions += duration
+		}
+	}
+	if elapsed > actions {
+		t.runOther += elapsed - actions
+	}
+}
+
+func (t *headlessTimingTrace) recordFailedRun(actions []headlessActionTiming, elapsed time.Duration) {
+	measured := time.Duration(0)
+	for _, action := range actions {
+		measured += action.duration
+		switch action.action {
+		case engine.ActionNavigate:
+			t.navigate += action.duration
+		case engine.ActionWaitLoad:
+			t.waitLoad += action.duration
+		case engine.ActionWaitDialog:
+			t.waitDialog += action.duration
+		default:
+			t.otherActions += action.duration
+		}
+	}
+	t.runOther += max(elapsed-measured, 0)
+}
+
+func (t *headlessTimingTrace) summary(elapsed time.Duration) (string, bool) {
+	if elapsed < headlessTimingOutlierMin && (!t.sampled || elapsed < headlessTimingSampleMin) {
+		return "", false
+	}
+	measured := t.rateWait + t.contextCreate + t.navigate + t.waitLoad + t.waitDialog + t.otherActions + t.runOther + t.cleanup
+	unattributed := max(elapsed-measured, 0)
+	return fmt.Sprintf(
+		"slow headless timing template_id=%q target_fingerprint=%s attempts=%d errors=%d total_ms=%d rate_wait_ms=%d context_create_ms=%d navigate_ms=%d waitload_ms=%d waitdialog_ms=%d other_actions_ms=%d run_other_ms=%d cleanup_ms=%d unattributed_ms=%d",
+		t.templateID, t.targetFingerprint, t.attempts, t.errors, elapsed.Milliseconds(), t.rateWait.Milliseconds(),
+		t.contextCreate.Milliseconds(), t.navigate.Milliseconds(), t.waitLoad.Milliseconds(), t.waitDialog.Milliseconds(),
+		t.otherActions.Milliseconds(), t.runOther.Milliseconds(), t.cleanup.Milliseconds(), unattributed.Milliseconds(),
+	), true
+}
+
+func (t *headlessTimingTrace) emit(logger *gologger.Logger) {
+	if message, ok := t.summary(time.Since(t.started)); ok {
+		if logger == nil {
+			logger = gologger.DefaultLogger
+		}
+		logger.Info().Msg(message)
+	}
+}

pkg/protocols/headless/timing_test.go

@@ -0,0 +1,127 @@
+package headless
+
+import (
+	"bytes"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/projectdiscovery/gologger"
+	"github.com/projectdiscovery/gologger/formatter"
+	"github.com/projectdiscovery/gologger/levels"
+	"github.com/projectdiscovery/nuclei/v3/pkg/protocols/headless/engine"
+	"github.com/stretchr/testify/require"
+)
+
+type timingCaptureWriter struct{ buffer *bytes.Buffer }
+
+func (w timingCaptureWriter) Write(data []byte, _ levels.Level) {
+	w.buffer.Write(data)
+}
+
+func TestHeadlessTimingTraceUsesExecutionLogger(t *testing.T) {
+	previous := gologger.DefaultLogger
+	t.Cleanup(func() { gologger.DefaultLogger = previous })
+	var output bytes.Buffer
+	silentLogger := &gologger.Logger{}
+	silentLogger.SetFormatter(formatter.NewCLI(false))
+	silentLogger.SetWriter(timingCaptureWriter{buffer: &output})
+	silentLogger.SetMaxLevel(levels.LevelSilent)
+	gologger.DefaultLogger = silentLogger
+	logger := &gologger.Logger{}
+	logger.SetFormatter(formatter.NewCLI(false))
+	logger.SetWriter(timingCaptureWriter{buffer: &output})
+	logger.SetMaxLevel(levels.LevelInfo)
+	trace := &headlessTimingTrace{templateID: "headless-open-redirect", sampled: true, started: time.Now().Add(-31 * time.Second)}
+
+	trace.emit(silentLogger)
+	trace.emit(nil)
+	require.Empty(t, output.String())
+
+	trace.emit(logger)
+	require.Contains(t, output.String(), "slow headless timing template_id=\"headless-open-redirect\"")
+}
+
+func TestHeadlessTimingTraceIsTemplateOptIn(t *testing.T) {
+	t.Setenv(headlessTimingTemplatesEnv, "")
+	require.Nil(t, newHeadlessTimingTrace("headless-open-redirect", "https://example.com"))
+
+	t.Setenv(headlessTimingTemplatesEnv, "CVE-2025-8191, headless-open-redirect")
+	require.Nil(t, newHeadlessTimingTrace("other-template", "https://example.com"))
+
+	trace := newHeadlessTimingTrace("headless-open-redirect", "https://example.com")
+	require.NotNil(t, trace)
+	require.Len(t, trace.targetFingerprint, 16)
+	require.NotContains(t, trace.targetFingerprint, "example.com")
+}
+
+func TestHeadlessTimingTraceAccountsForActionsAndOverhead(t *testing.T) {
+	trace := &headlessTimingTrace{
+		templateID:        "headless-open-redirect",
+		targetFingerprint: "0123456789abcdef",
+		sampled:           true,
+		attempts:          2,
+		errors:            1,
+		rateWait:          time.Second,
+		contextCreate:     time.Second,
+		cleanup:           250 * time.Millisecond,
+	}
+	steps := []*engine.Action{
+		{ActionType: engine.ActionTypeHolder{ActionType: engine.ActionNavigate}},
+		{ActionType: engine.ActionTypeHolder{ActionType: engine.ActionWaitLoad}},
+		{ActionType: engine.ActionTypeHolder{ActionType: engine.ActionWaitDialog}},
+	}
+	trace.recordRun(steps, []time.Duration{2 * time.Second, 500 * time.Millisecond, 3 * time.Second}, 6*time.Second)
+
+	message, ok := trace.summary(30 * time.Second)
+	require.True(t, ok)
+	for _, field := range []string{
+		"attempts=2", "errors=1", "total_ms=30000", "rate_wait_ms=1000",
+		"context_create_ms=1000", "navigate_ms=2000", "waitload_ms=500",
+		"waitdialog_ms=3000", "run_other_ms=500", "cleanup_ms=250", "unattributed_ms=21750",
+	} {
+		require.True(t, strings.Contains(message, field), "missing %s in %s", field, message)
+	}
+	require.NotContains(t, message, "https://")
+}
+
+func TestHeadlessTimingTraceBoundsOutput(t *testing.T) {
+	trace := &headlessTimingTrace{sampled: false}
+	_, ok := trace.summary(4 * time.Minute)
+	require.False(t, ok)
+	_, ok = trace.summary(5 * time.Minute)
+	require.True(t, ok)
+
+	trace.sampled = true
+	_, ok = trace.summary(29 * time.Second)
+	require.False(t, ok)
+	_, ok = trace.summary(30 * time.Second)
+	require.True(t, ok)
+}
+
+func TestHeadlessTimingTraceDoesNotMisattributePartialActionDurations(t *testing.T) {
+	trace := &headlessTimingTrace{sampled: true}
+	steps := []*engine.Action{
+		{ActionType: engine.ActionTypeHolder{ActionType: engine.ActionNavigate}},
+		{ActionType: engine.ActionTypeHolder{ActionType: engine.ActionWaitLoad}},
+	}
+	trace.recordRun(steps, []time.Duration{2 * time.Second}, 3*time.Second)
+
+	require.Zero(t, trace.navigate)
+	require.Zero(t, trace.waitLoad)
+	require.Equal(t, 2*time.Second, trace.otherActions)
+	require.Equal(t, time.Second, trace.runOther)
+}
+
+func TestHeadlessTimingTraceAttributesFailedActions(t *testing.T) {
+	trace := &headlessTimingTrace{sampled: true}
+	trace.recordFailedRun([]headlessActionTiming{
+		{action: engine.ActionNavigate, duration: 2 * time.Second},
+		{action: engine.ActionWaitLoad, duration: 500 * time.Millisecond},
+	}, 3*time.Second)
+
+	require.Equal(t, 2*time.Second, trace.navigate)
+	require.Equal(t, 500*time.Millisecond, trace.waitLoad)
+	require.Zero(t, trace.otherActions)
+	require.Equal(t, 500*time.Millisecond, trace.runOther)
+}