Skip to content

Commit 967f7c3

Browse files
DivModeDivMode
authored
feat(cf): distinguish verified-but-closed from rejected sessions (⊘ label) (#119)
* feat(tracing): add OOPIF target diagnostic spans for wrong-target click analysis Phase 2 logs all OOPIF candidates (target IDs, URLs, parentFrameIds) and the selected target with match method. Phase 4 verifies OOPIF identity via location.href before clicking and adds detailed checkbox state to the verification span. Detection logs the OOPIF target it found so traces can cross-reference detection → phase2 → phase4 target consistency. Motivated by trace 929765cb showing click_delivered=true but zero widget reaction — suspected wrong OOPIF when has_iframe_frame_id=false. * feat(cf): distinguish verified-but-closed from rejected CF sessions (⊘ label) When CF shows "Verification successful" but the browser closes before the origin responds, the system previously reported Int✗ session_close — identical to a genuine CF rejection. This introduces a new ⊘ label to make the distinction clear across all layers. - Fix dual emission bug in unregister() (cf.solved + cf.failed for same detection) - Add verificationEvidence field to ActiveDetection (cosmetic_nav | oopif_success) - Add verified_session_close signal and ⊘ label via deriveFailLabel - Change emitFallback from emitSolved to emitFailed for session_close (breaking) - Add cf_verified to emitFailed, CDP events, replay markers, and Tempo spans - Add cf_verified to TurnstileSummary and buildSummaryFromMarkers - Add 7 new tests for ⊘ labels and verified_session_close
1 parent 6e72039 commit 967f7c3

8 files changed

Lines changed: 222 additions & 24 deletions

‎src/session/cf/cf-detection-registry.ts‎

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -94,8 +94,12 @@ export class DetectionRegistry {
9494
// Orphaned detection — abort + settle Resolution + emit session_close fallback
9595
DetectionContext.setAborted(active);
9696
const duration = Date.now() - active.startTime;
97-
yield* active.resolution.fail('session_close', duration);
98-
self.emitFallback(active, 'session_close');
97+
const reason = active.verificationEvidence ? 'verified_session_close' : 'session_close';
98+
yield* active.resolution.fail(reason, duration);
99+
// Only emit fallback if onSettle didn't already handle it
100+
if (!active.resolution.markerEmitted) {
101+
self.emitFallback(active, reason);
102+
}
99103
}
100104
}));
101105

@@ -121,10 +125,14 @@ export class DetectionRegistry {
121125
if (!context.resolved) {
122126
const mutable = context.mutableActive;
123127
const duration = Date.now() - mutable.startTime;
128+
const reason = mutable.verificationEvidence ? 'verified_session_close' : 'session_close';
124129
if (!mutable.resolution.isDone) {
125-
yield* mutable.resolution.fail('session_close', duration);
130+
yield* mutable.resolution.fail(reason, duration);
131+
}
132+
// Only emit fallback if onSettle didn't already handle it
133+
if (!mutable.resolution.markerEmitted) {
134+
self.emitFallback(context.active, reason);
126135
}
127-
self.emitFallback(context.active, 'session_close');
128136
context.resolved = true;
129137
}
130138
yield* Scope.close(context.scope, Exit.void);

‎src/session/cf/cf-phase-oopif.ts‎

Lines changed: 37 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -67,7 +67,20 @@ export function phase2OOPIFResolution(
6767
&& !isCFTestWidget(t.url),
6868
);
6969

70+
// ── Diagnostic: Log all OOPIF candidates for wrong-target analysis ──
71+
yield* Effect.annotateCurrentSpan({
72+
'cf.phase2.total_targets': targetInfos.length,
73+
'cf.phase2.cf_candidates': candidates.length,
74+
'cf.phase2.candidate_ids': candidates.map((t: any) => t.targetId?.substring(0, 16)).join(','),
75+
'cf.phase2.candidate_urls': candidates.map((t: any) => (t.url || '').substring(0, 80)).join(' | '),
76+
'cf.phase2.candidate_parents': candidates.map((t: any) => (t.parentFrameId || 'none').substring(0, 16)).join(','),
77+
});
78+
7079
let oopifSessionId: CdpSessionId | null = null;
80+
let selectedTargetId: string | null = null;
81+
let selectedUrl: string | null = null;
82+
let selectedParentFrame: string | null = null;
83+
let matchMethod: string | null = null;
7184

7285
// ── Instrumentation: Phase 2 timing ─────────────────────────────
7386
const phase2Start = Date.now();
@@ -104,6 +117,10 @@ export function phase2OOPIFResolution(
104117

105118
if (frameId === iframeFrameId || target.targetId === iframeFrameId) {
106119
oopifSessionId = trySessionId;
120+
selectedTargetId = target.targetId;
121+
selectedUrl = target.url ?? null;
122+
selectedParentFrame = target.parentFrameId ?? null;
123+
matchMethod = 'frameId_match';
107124
yield* events.marker(pageTargetId, 'cf.oopif_discovered', {
108125
method: 'active', via,
109126
filter: 'frameId_match',
@@ -158,6 +175,10 @@ export function phase2OOPIFResolution(
158175
const frameId = ft?.frameTree?.frame?.id;
159176
if (frameId && (frameId === iframeFrameId || target.targetId === iframeFrameId)) {
160177
oopifSessionId = trySessionId;
178+
selectedTargetId = target.targetId;
179+
selectedUrl = target.url ?? null;
180+
selectedParentFrame = target.parentFrameId ?? null;
181+
matchMethod = 'frameId_match_retry';
161182
yield* events.marker(pageTargetId, 'cf.oopif_discovered', {
162183
method: 'active', via,
163184
filter: 'frameId_match_retry',
@@ -186,6 +207,11 @@ export function phase2OOPIFResolution(
186207

187208
if (cfTargets.length === 0) cfTargets = candidates;
188209

210+
yield* Effect.annotateCurrentSpan({
211+
'cf.phase2.page_frame_id': pageFrameId?.substring(0, 16) ?? 'null',
212+
'cf.phase2.parent_filtered_count': cfTargets.length,
213+
});
214+
189215
if (cfTargets.length > 0) {
190216
const target = cfTargets[0];
191217
const attachStart = Date.now();
@@ -218,6 +244,10 @@ export function phase2OOPIFResolution(
218244
}
219245
}
220246
oopifSessionId = sessionId;
247+
selectedTargetId = target.targetId;
248+
selectedUrl = target.url ?? null;
249+
selectedParentFrame = target.parentFrameId ?? null;
250+
matchMethod = pageFrameId ? 'parentFrameId' : 'url';
221251
yield* events.marker(pageTargetId, 'cf.oopif_discovered', {
222252
method: 'active', via,
223253
filter: pageFrameId ? 'parentFrameId' : 'url',
@@ -231,7 +261,13 @@ export function phase2OOPIFResolution(
231261
}
232262
}
233263

234-
yield* Effect.annotateCurrentSpan({ 'cf.oopif_found': !!oopifSessionId });
264+
yield* Effect.annotateCurrentSpan({
265+
'cf.oopif_found': !!oopifSessionId,
266+
'cf.phase2.selected_target_id': selectedTargetId?.substring(0, 16) ?? 'none',
267+
'cf.phase2.selected_url': selectedUrl?.substring(0, 80) ?? 'none',
268+
'cf.phase2.selected_parent_frame': selectedParentFrame?.substring(0, 16) ?? 'none',
269+
'cf.phase2.match_method': matchMethod ?? 'none',
270+
});
235271
yield* events.marker(pageTargetId, 'cf.phase2_end', {
236272
found: !!oopifSessionId,
237273
elapsed_ms: Date.now() - phase2Start,

‎src/session/cf/cf-summary.ts‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,8 @@ export interface TurnstileSummary {
6767
durationMs?: number;
6868
/** Whether a rechallenge was detected */
6969
rechallenge: boolean;
70+
/** Whether CF verification passed before session closed (⊘ label) */
71+
cf_verified?: boolean;
7072
}
7173

7274
// ── Phase-walking internals ──────────────────────────────────────────
@@ -162,13 +164,19 @@ export function buildSummaryFromMarkers(markers: ReplayMarker[]): TurnstileSumma
162164
const rechallenge = markers.some(m => m.tag === 'cf.rechallenge');
163165
const lastSolved = [...phases].reverse().find(p => p.method);
164166

167+
// Check for verified_session_close in any failed marker
168+
const cfVerified = sorted.some(m =>
169+
m.tag === 'cf.failed' && m.payload.cf_verified === true
170+
);
171+
165172
return {
166173
label,
167174
type: phases[0].type,
168175
method: lastSolved?.method || '',
169176
signal: lastSolved?.signal,
170177
durationMs: lastSolved?.durationMs,
171178
rechallenge,
179+
cf_verified: cfVerified || undefined,
172180
};
173181
}
174182

‎src/session/cf/cloudflare-detector.ts‎

Lines changed: 17 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -370,6 +370,7 @@ export class CloudflareDetector {
370370
// Set one-shot flag so the NEXT targetInfoChanged (title update or real nav)
371371
// falls through to InterstitialSolved instead of being swallowed here again.
372372
active.cosmeticNavSeen = true;
373+
active.verificationEvidence = 'cosmetic_nav';
373374
self.events.marker(targetId, 'cf.cosmetic_url_change', {
374375
title: outcome.title.substring(0, 50), url: outcome.url.substring(0, 200),
375376
});
@@ -674,20 +675,24 @@ export class CloudflareDetector {
674675
const label = self.state.buildCompoundLabel(targetId);
675676
self.events.emitSolved(active, resolved.result, label, { skipMarker: active.resolution.markerEmitted });
676677
} else {
678+
const cfVerified = resolved.reason === 'verified_session_close';
677679
yield* Effect.annotateCurrentSpan({
678680
'cf.resolution_outcome': 'failed',
679681
'cf.fail_reason': resolved.reason,
680682
'cf.elapsed_ms': resolved.duration_ms,
683+
'cf.verified': cfVerified,
681684
});
682685
yield* Effect.logWarning('CF lifecycle: resolution_result').pipe(
683-
Effect.annotateLogs({ target_id: targetId.slice(0, 8), session_id: self.sid, result: 'failed', reason: resolved.reason, elapsed_ms: resolved.duration_ms }),
686+
Effect.annotateLogs({ target_id: targetId.slice(0, 8), session_id: self.sid, result: 'failed', reason: resolved.reason, elapsed_ms: resolved.duration_ms, cf_verified: cfVerified }),
684687
);
685688
if (!active.resolution.markerEmitted) {
686-
const phase_label = resolved.phase_label ?? `✗ ${resolved.reason}`;
689+
const phase_label = cfVerified ? '⊘' : (resolved.phase_label ?? `✗ ${resolved.reason}`);
687690
self.state.pushPhase(targetId, active.info.type, phase_label);
688691
}
689692
const label = self.state.buildCompoundLabel(targetId);
690-
self.events.emitFailed(active, resolved.reason, resolved.duration_ms, resolved.phase_label, label, { skipMarker: active.resolution.markerEmitted });
693+
self.events.emitFailed(active, resolved.reason, resolved.duration_ms,
694+
cfVerified ? '⊘' : resolved.phase_label, label,
695+
{ skipMarker: active.resolution.markerEmitted, cf_verified: cfVerified });
691696
}
692697
} else {
693698
// Timeout — zombie detection caught. Settle and emit.
@@ -780,10 +785,14 @@ export class CloudflareDetector {
780785
phase_label: outcome.result.phase_label, signal: outcome.result.signal,
781786
});
782787
} else {
783-
const phase_label = outcome.phase_label ?? `✗ ${outcome.reason}`;
788+
const cfVerified = outcome.reason === 'verified_session_close';
789+
const phase_label = cfVerified
790+
? '⊘'
791+
: (outcome.phase_label ?? `✗ ${outcome.reason}`);
784792
self.state.pushPhase(targetId, active.info.type, phase_label);
785793
self.events.marker(targetId, 'cf.failed', {
786794
reason: outcome.reason, duration_ms: outcome.duration_ms, phase_label,
795+
cf_verified: cfVerified,
787796
});
788797
}
789798
}),
@@ -977,6 +986,10 @@ export class CloudflareDetector {
977986
'cf.target_id': targetId,
978987
'cf.type': 'turnstile',
979988
'cf.detection_method': 'cdp_dom_walk',
989+
'cf.detect.oopif_target_id': detection.targets[0]?.targetId?.substring(0, 16) ?? 'none',
990+
'cf.detect.oopif_url': detection.targets[0]?.url?.substring(0, 80) ?? 'none',
991+
'cf.detect.sitekey': meta?.sitekey ?? 'none',
992+
'cf.detect.target_count': detection.targets.length,
980993
});
981994
const rechallengeCount = self.state.pendingRechallengeCount.get(targetId) || 0;
982995
self.state.pendingRechallengeCount.delete(targetId);

‎src/session/cf/cloudflare-event-emitter.ts‎

Lines changed: 12 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -179,6 +179,13 @@ export interface ActiveDetection {
179179
abortLatch: Latch.Latch;
180180
/** Parsed metadata from the Turnstile OOPIF URL (sitekey, rechallenge, mode). */
181181
oopifMeta?: TurnstileOOPIFMeta;
182+
/**
183+
* Evidence that CF verification passed, independent of session lifecycle.
184+
* 'cosmetic_nav' — CF stripped __cf_chl_rt_tk from URL (interstitial verification underway/complete)
185+
* 'oopif_success' — OOPIF iframe reported state='success' (turnstile widget solved inside interstitial)
186+
* undefined = no evidence of verification.
187+
*/
188+
verificationEvidence?: 'cosmetic_nav' | 'oopif_success';
182189
/**
183190
* Resolution gateway — exactly-once emission for CF solve/fail outcomes.
184191
* Multiple concurrent fibers race to complete it via Deferred.succeed (idempotent).
@@ -285,26 +292,28 @@ export function createCFEvents(
285292
}
286293
},
287294

288-
emitFailed(active: ReadonlyActiveDetection, reason: string, duration: number, phaseLabel?: string, cf_summary_label?: string, options?: { skipMarker?: boolean }): void {
295+
emitFailed(active: ReadonlyActiveDetection, reason: string, duration: number, phaseLabel?: string, cf_summary_label?: string, options?: { skipMarker?: boolean; cf_verified?: boolean }): void {
289296
const phase_label = phaseLabel ?? `✗ ${reason}`;
297+
const cfVerified = options?.cf_verified ?? false;
290298
const snap = active.tracker.snapshot();
291299
const isRechallenge = (active.rechallengeCount ?? 0) > 0;
292300
const diag = snap.widget_diag;
293301
const diagStr = diag ? ` diag_alive=${diag.alive} diag_cbI=${diag.cbI} diag_inp=${diag.inp} diag_shadow=${diag.shadow} diag_bodyLen=${diag.bodyLen}` : '';
294302
const timingStr = snap.checkbox_to_click_ms != null
295303
? ` checkbox_to_click_ms=${snap.checkbox_to_click_ms} phase4_ms=${snap.phase4_duration_ms}`
296304
: '';
297-
runForkInServer(Effect.logWarning(`CF failed: session=${sessionId.slice(0,8)} reason=${reason} type=${active.info.type} method=${active.info.detectionMethod} target=${active.pageTargetId.slice(0, 8)} duration=${duration}ms attempts=${active.attempt} oopif_url=${active.info.url || 'none'} rechallenge=${isRechallenge} widget_error_count=${snap.widget_error_count} widget_error_type=${snap.widget_error_type ?? 'none'} click_count=${snap.click_count} false_positives=${snap.false_positive_count}${diagStr}${timingStr}`));
305+
runForkInServer(Effect.logWarning(`CF failed: session=${sessionId.slice(0,8)} reason=${reason} type=${active.info.type} method=${active.info.detectionMethod} target=${active.pageTargetId.slice(0, 8)} duration=${duration}ms attempts=${active.attempt} oopif_url=${active.info.url || 'none'} rechallenge=${isRechallenge} cf_verified=${cfVerified} widget_error_count=${snap.widget_error_count} widget_error_type=${snap.widget_error_type ?? 'none'} click_count=${snap.click_count} false_positives=${snap.false_positive_count}${diagStr}${timingStr}`));
298306
emitClientEvent('Browserless.cloudflareFailed', {
299307
reason, type: active.info.type, duration_ms: duration, attempts: active.attempt,
300308
targetId: active.pageTargetId,
301309
oopif_url: active.info.url,
302310
summary: snap,
303311
phase_label,
304312
cf_summary_label,
313+
cf_verified: cfVerified,
305314
}).catch((e) => runForkInServer(Effect.logDebug(`emitFailed failed: ${e instanceof Error ? e.message : String(e)}`)));
306315
if (!options?.skipMarker) {
307-
marker(active.pageTargetId, 'cf.failed', { reason, duration_ms: duration, phase_label, oopif_url: active.info.url, rechallenge: isRechallenge });
316+
marker(active.pageTargetId, 'cf.failed', { reason, duration_ms: duration, phase_label, oopif_url: active.info.url, rechallenge: isRechallenge, cf_verified: cfVerified });
308317
}
309318
},
310319

‎src/session/cf/cloudflare-solve-strategies.ts‎

Lines changed: 31 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -587,6 +587,23 @@ export class CloudflareSolveStrategies {
587587
// Bare press + hold + release — NO mouseMoved (matches pydoll exactly).
588588
// mouseMoved causes 283-5600ms compositor init stall on isolated WS.
589589
const { pressResponse, releaseResponse, holdMs } = yield* Effect.fn('cf.phase4_dispatch')(function*() {
590+
yield* Effect.annotateCurrentSpan({
591+
'cf.phase4.oopif_session_id': oopifSessionId.substring(0, 16),
592+
'cf.phase4.click_x': clickX,
593+
'cf.phase4.click_y': clickY,
594+
'cf.phase4.page_abs_x': pageAbsX ?? 'null',
595+
'cf.phase4.page_abs_y': pageAbsY ?? 'null',
596+
});
597+
598+
// ── Diagnostic: Verify OOPIF identity before click ──
599+
const oopifUrlResult = yield* verifySend('Runtime.evaluate', {
600+
expression: 'location.href',
601+
returnByValue: true,
602+
}, oopifSessionId).pipe(Effect.orElseSucceed(() => null));
603+
yield* Effect.annotateCurrentSpan({
604+
'cf.phase4.oopif_url': ((oopifUrlResult as any)?.result?.value || 'unknown').substring(0, 100),
605+
});
606+
590607
// Install click verification listener (OOPIF session — safe, separate V8 isolate)
591608
yield* verifySend('Runtime.evaluate', {
592609
expression: `window.__bClkV=false;document.addEventListener('mousedown',function(){window.__bClkV=true},{once:true,capture:true});true`,
@@ -648,7 +665,20 @@ export class CloudflareSolveStrategies {
648665
verifyError = verifyResult;
649666
}
650667

651-
yield* Effect.annotateCurrentSpan({ 'cf.click_verified': clickVerified });
668+
// ── Diagnostic: Detailed checkbox state for wrong-OOPIF analysis ──
669+
const detailResult = yield* verifySend('Runtime.evaluate', {
670+
expression: `JSON.stringify({
671+
clicked: window.__bClkV,
672+
checkboxChecked: document.querySelector('[type="checkbox"]')?.checked ?? null,
673+
activeTag: document.activeElement?.tagName ?? null,
674+
})`,
675+
returnByValue: true,
676+
}, oopifSessionId).pipe(Effect.orElseSucceed(() => null));
677+
678+
yield* Effect.annotateCurrentSpan({
679+
'cf.click_verified': clickVerified,
680+
'cf.phase4.verify_detail': (detailResult as any)?.result?.value ?? 'null',
681+
});
652682
return { clickVerified, verifyError };
653683
})();
654684

‎src/session/cf/cloudflare-state-tracker.ts‎

Lines changed: 22 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -37,7 +37,8 @@ export type SendCommand = (method: string, params?: object, cdpSessionId?: CdpSe
3737
// └──────────────┴──────────────────┴──────────────┴───────┘
3838

3939
export type SolveSignal = 'page_navigated' | 'beacon_push' | 'token_poll' | 'activity_poll'
40-
| 'bridge_solved' | 'state_change' | 'callback_binding' | 'session_close' | 'cdp_dom_walk';
40+
| 'bridge_solved' | 'state_change' | 'callback_binding' | 'session_close' | 'cdp_dom_walk'
41+
| 'verified_session_close';
4142

4243
export function deriveSolveAttribution(signal: SolveSignal, clickDelivered: boolean) {
4344
// Interstitials: page navigated away from CF challenge page
@@ -55,6 +56,7 @@ export function deriveSolveAttribution(signal: SolveSignal, clickDelivered: bool
5556
}
5657

5758
export function deriveFailLabel(reason: string) {
59+
if (reason === 'verified_session_close') return { label: '⊘' };
5860
return { label: `✗ ${reason}` };
5961
}
6062

@@ -115,15 +117,24 @@ export class CloudflareStateTracker {
115117
) {
116118
this.registry = new DetectionRegistry((active, signal) => {
117119
const duration = Date.now() - active.startTime;
118-
const attr = deriveSolveAttribution(signal, !!active.clickDelivered);
119-
runForkInServer(Effect.logInfo(`Scope finalizer fallback: emitting solved for orphaned detection on ${active.pageTargetId}`));
120-
this.pushPhase(active.pageTargetId, active.info.type, attr.label);
121-
const label = this.buildCompoundLabel(active.pageTargetId);
122-
this.events.emitSolved(active, {
123-
solved: true, type: active.info.type, method: attr.method,
124-
duration_ms: duration, attempts: 0, auto_resolved: attr.autoResolved,
125-
signal, token_length: 0, phase_label: attr.label,
126-
}, label);
120+
121+
if (signal === 'verified_session_close') {
122+
// CF verified but session closed before navigation completed
123+
const phaseLabel = '⊘';
124+
runForkInServer(Effect.logInfo(`Scope finalizer fallback: verified_session_close for ${active.pageTargetId}`));
125+
this.pushPhase(active.pageTargetId, active.info.type, phaseLabel);
126+
const compoundLabel = this.buildCompoundLabel(active.pageTargetId);
127+
this.events.emitFailed(active, 'verified_session_close', duration, phaseLabel, compoundLabel,
128+
{ cf_verified: true });
129+
return;
130+
}
131+
132+
// Genuine session_close — emit as failure (session closed before resolution)
133+
const failLabel = `✗ ${signal}`;
134+
runForkInServer(Effect.logInfo(`Scope finalizer fallback: emitting failed for orphaned detection on ${active.pageTargetId}`));
135+
this.pushPhase(active.pageTargetId, active.info.type, failLabel);
136+
const compoundLabel = this.buildCompoundLabel(active.pageTargetId);
137+
this.events.emitFailed(active, signal, duration, failLabel, compoundLabel);
127138
});
128139
}
129140

@@ -150,6 +161,7 @@ export class CloudflareStateTracker {
150161
// CF hasn't redirected yet. Resolving here would close the browser too early → rechallenge.
151162
// Let the page_navigated signal handle interstitial resolution.
152163
if (isInterstitialType(active.info.type)) {
164+
active.verificationEvidence = 'oopif_success';
153165
yield* Effect.logInfo(`OOPIF success for interstitial ${pageTargetId} — waiting for page navigation`);
154166
tracker.events.marker(active.pageTargetId, 'cf.oopif_success_interstitial', {
155167
waiting_for: 'page_navigated',

0 commit comments

Comments
 (0)