Skip to content

Commit f57b421

Browse files
authored
fix(network): report iOS requests that reused a keep-alive connection (#2433)
* fix(network): report iOS requests that reused a keep-alive connection CFNetwork logs a request URL only on the `com.apple.network:connection` line that opens a connection. A request that reuses a keep-alive connection emits a task summary carrying status, timing, and byte counts but no URL anywhere in the log, so a URL-keyed reader dropped it and the dump silently omitted a request that did happen. An "assert this endpoint was called on startup" check therefore read as a definite fail. Correlate a reused task summary with the connection it names and report it against that connection's origin, with `pathUnavailable` set, its status, and its timing. The request path is not in the log at all, so the dump also notes how many requests it could not name — a gap in observation now reads as a gap rather than as a negative observation. Also stop a URL parsed out of a log line from carrying the punctuation that follows it, so an entry's `url` compares equal to the endpoint under test instead of failing on a trailing comma. The correlation lives in the reader rather than a sibling module because `packages/capture-kit/src/index.ts` may not grow its eager import closure. Refs #2430 * fix(network): count keep-alive requests the reader cannot name at all Review of the parent commit found the same definite-negative it fixes, one level down: a reused task summary whose connection was opened before the scanned window resolves to no origin, so it produced no entry and no signal — an empty dump reporting "No HTTP(s) entries were found" for a window that demonstrably carried traffic. Count those in the dump's `unnamedRequests` and say so in the notes, so an unnameable request is still a reported observation. Also order the Apple note builders so the keep-alive note no longer trips the `notes.length === 0` guard that suppresses lifecycle guidance, and give the android-backend test a fixture an Apple dump would actually resolve, so the backend gate it names is the thing it proves. * fix(network): scope connection correlation to the process that opened it Review findings on the parent commits: three ways the reader still answers with something other than what it observed. A connection number is only meaningful within one process, but the index keyed on the number alone, so an app that relaunched and reopened the same number inherited the origin its predecessor had contacted — a request attributed to a host it never reached, which is worse than dropping it. Key the index by the compact log's `name[pid]` and the connection number together; a line whose process cannot be read correlates to nothing and its traffic stays unnamed. The simulator recovery pass merged its dump only when it carried entries, so a recovery window holding nothing but unnameable reused-task summaries discarded that count and the response still reported an empty window. Merge whenever the pass observed traffic in either form, and reserve the "none looked like HTTP traffic" note for a pass that found neither. The trailing-separator strip was global, so a valid URL ending in punctuation became a different endpoint. Take the URL from the delimited `url:` field where the format establishes the separator, and leave a bare URL exactly as matched. Regressions cover each: the same connection number under a different pid, an unreadable process identity, recovery-only unnamed traffic, and a path that legitimately ends in a period. * fix(network): reconcile unnamed keep-alive requests across scan windows The app log and the simulator recovery pass cover different, sometimes overlapping windows, so taking the larger of their two unnamed counts was wrong in both directions: two unnameable requests in one window and three in the other reported three rather than five, and a request the recovery pass resolved stayed counted as unnamed from the app log. Carry the identities instead of a count. Every CFNetwork line names its request as `Task <UUID>.<seq>`, scoped here to the emitting process, so the same request seen in two windows is recognisable as one. A merge unions the unnamed identities and subtracts anything either window managed to name, and a resolved reused request carries its identity as `packetId` so that subtraction has something to key on. `NetworkDump.unnamedRequests` becomes `unnamedRequestIds`, since a list of identities is what makes the reconciliation exact rather than a lower bound. Regressions cover disjoint windows, overlapping windows, and a request one window named while the other could not. * fix(network): keep unnamed-request identities out of the response `unnamedRequestIds` collected every unresolved task in the scan window and was spread straight into the response, so `network dump 1` could answer with thousands of task ids: an output whose size tracked the log rather than the requested entry limit. The identities exist to reconcile two scan windows, which is a step that finishes before a dump is returned. Keep them there. `NetworkDump` carries `unnamedRequests` as a count again, bounded by construction; the identities ride `ScannedNetworkDump`, the internal widening that the reader and the merge speak, and the Apple runtime projects them away with `withoutScanIdentities` on the way out. Reconciliation is unchanged: overlapping windows still collapse to one request and disjoint windows still sum, because the merge still sees the identities and recomputes the count from them. Regression: five unnameable tasks against `maxEntries: 1` reports all five and exposes no identity list. * fix(network): return scan identities beside the dump, not on it The Apple route stopped leaking task identities into its response, but Limrun and WebDriver return the scanner result directly and both serve Apple sessions, so an iOS `network dump 1` through either still answered with every unresolved task id in the scan window. Projecting at one producer was never going to hold: `ScannedNetworkDump` was assignable to `NetworkDump`, so returning the scanner result compiled everywhere and each producer had to remember not to. Take the shape away instead. `readRecentNetworkTrafficFromText` returns a `NetworkScan` — `{ dump, unnamedRequestIds }` — so identities sit beside the public dump rather than on it, and `mergeNetworkScans` reconciles the pair. A route returning `scan.dump` cannot carry them out, and a route that forgets does not compile. All four producers are updated; the response shape is unchanged. Regressions cover the Apple, Limrun and WebDriver routes: five unnameable tasks against `maxEntries: 1` report the count and expose no identity list. All three fail if the identities are put back on the dump.
1 parent 72ccf1a commit f57b421

17 files changed

Lines changed: 793 additions & 68 deletions

File tree

‎CHANGELOG.md‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,20 @@
2121
disclosing that through `truncated`/`effectiveDepth` as it does unscoped.
2222
- Fixed: repeated unfiltered Android snapshots stay compact when identical element bounds arrive
2323
with a different property order. Changes to the bounds still re-emit the tree.
24+
- Fixed: iOS `network dump` no longer omits requests that reused a keep-alive connection.
25+
CFNetwork logs a request URL only on the line that opens a connection, so a second request to
26+
the same host produced no `url:` line and was dropped from the dump entirely — an "this endpoint
27+
was called" check read as a definite fail. Such a request is now reported against the origin its
28+
connection was opened for, with `pathUnavailable` set, its status, and its timing. A reused
29+
request whose connection was opened before the scanned window cannot be named at all; those are
30+
counted in the dump's `unnamedRequests`, so an empty result still reports that traffic was
31+
observed. The identities behind that count reconcile the app-log and recovery windows internally
32+
— so overlapping traffic is not double-counted and disjoint traffic is not under-reported — but
33+
the response carries only the count, which stays bounded however large the scan window was. The notes say absence of an endpoint does not prove it was not called.
34+
- Fixed: a URL logged as a delimited `url: <value>,` field no longer keeps the separator the log
35+
format put after it, so an entry's `url` compares equal to the endpoint under test. A bare URL
36+
elsewhere is left alone, since nothing there establishes that trailing punctuation is not part of
37+
the path.
2438
- Added: `replay export` supports flows that switch apps and return, preserving each
2539
`open <appId>` target as an explicit Maestro `launchApp.appId`.
2640
- Added: `replay export` converts recorded `home` actions to Maestro `pressKey: Home`, allowing

‎packages/capture-kit/src/index.ts‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,4 +29,8 @@ export {
2929
appLogSessionArtifactsMatch,
3030
assertAppLogSessionArtifacts,
3131
} from './app-log-session-artifacts.ts';
32-
export { mergeNetworkDumps, readRecentNetworkTrafficFromText } from './network-traffic.ts';
32+
export {
33+
mergeNetworkScans,
34+
readRecentNetworkTrafficFromText,
35+
type NetworkScan,
36+
} from './network-traffic.ts';

‎packages/capture-kit/src/network-traffic-android.test.ts‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@ import { test } from 'vitest';
33
import { readRecentNetworkTrafficFromText } from './network-traffic.ts';
44

55
test('preserves Android adjacent packet enrichment', () => {
6-
const dump = readRecentNetworkTrafficFromText(
6+
const { dump } = readRecentNetworkTrafficFromText(
77
[
88
'03-31 17:43:32.564 V/GIBSDK (17434): [NetworkAgent]: packet id 23911610 added, queue size: 1',
99
'03-31 17:43:32.700 V/OtherTag (17434): unrelated line 1',

‎packages/capture-kit/src/network-traffic.test.ts‎

Lines changed: 218 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,9 @@
11
import assert from 'node:assert/strict';
22
import { test } from 'vitest';
3-
import { mergeNetworkDumps, readRecentNetworkTrafficFromText } from './network-traffic.ts';
3+
import { mergeNetworkScans, readRecentNetworkTrafficFromText } from './network-traffic.ts';
44

55
test('parses the existing include projections and newest-first order', () => {
6-
const dump = readRecentNetworkTrafficFromText(
6+
const { dump } = readRecentNetworkTrafficFromText(
77
[
88
'2026-02-24T10:00:00Z GET https://api.example.com/profile status=200',
99
'2026-02-24T10:00:02Z {"method":"POST","url":"https://api.example.com/login","statusCode":401,"headers":{"x-id":"abc"},"requestBody":{"email":"u@example.com"},"responseBody":{"error":"denied"}}',
@@ -35,7 +35,7 @@ test('parses the existing include projections and newest-first order', () => {
3535
});
3636

3737
test('keeps missing canonical app-log text distinct and merges recovery first', () => {
38-
const missing = readRecentNetworkTrafficFromText('', {
38+
const { dump: missing } = readRecentNetworkTrafficFromText('', {
3939
path: '/sessions/one/app.log',
4040
exists: false,
4141
backend: 'android',
@@ -65,17 +65,18 @@ test('keeps missing canonical app-log text distinct and merges recovery first',
6565
scannedLines: 0,
6666
matchedLines: 0,
6767
entries: [],
68+
unnamedRequests: 0,
6869
include: 'summary',
6970
limits: { maxEntries: 2, maxPayloadChars: 2048, maxScanLines: 100 },
7071
});
7172
assert.deepEqual(
72-
mergeNetworkDumps(recovered, stale, 2).entries.map(({ url }) => url),
73+
mergeNetworkScans(recovered, stale, 2).dump.entries.map(({ url }) => url),
7374
['https://fresh.example.test', 'https://stale.example.test'],
7475
);
7576
});
7677

7778
test('keeps Android adjacent enrichment disabled for Apple backends', () => {
78-
const dump = readRecentNetworkTrafficFromText(
79+
const { dump } = readRecentNetworkTrafficFromText(
7980
[
8081
'2026-03-31 17:43:33.031 response code: 200',
8182
'2026-03-31 17:43:33.032 URL: https://api.example.com/fixture',
@@ -96,7 +97,7 @@ test('keeps Android adjacent enrichment disabled for Apple backends', () => {
9697
});
9798

9899
test('ignores documentation URLs without an explicit network signal', () => {
99-
const dump = readRecentNetworkTrafficFromText(
100+
const { dump } = readRecentNetworkTrafficFromText(
100101
'2026-04-02 08:14:44Z config warning. See https://docs.example.test/setup for help.\n',
101102
{
102103
path: '/sessions/one/app.log',
@@ -123,7 +124,7 @@ test('applies a validated absolute line offset to host-selected text', () => {
123124
maxScanLines: 100,
124125
};
125126

126-
const dump = readRecentNetworkTrafficFromText('GET https://example.test status=200', {
127+
const { dump } = readRecentNetworkTrafficFromText('GET https://example.test status=200', {
127128
...options,
128129
lineNumberOffset: 5000,
129130
});
@@ -137,3 +138,213 @@ test('applies a validated absolute line offset to host-selected text', () => {
137138
/non-negative integer/,
138139
);
139140
});
141+
142+
test('a URL logged mid-sentence drops the separator that follows it', () => {
143+
const line =
144+
'2026-09-09 18:22:27.805 Df spicygolf[33656:4505afd] [com.apple.network:connection] [C9 Hostname#c6f77afc:3040 tcp, url: http://localhost:3040/v4/messages/en_US, definite, attribution: developer] start';
145+
const { dump } = readRecentNetworkTrafficFromText(`${line}\n`, {
146+
path: 'app.log',
147+
exists: true,
148+
backend: 'ios-simulator',
149+
});
150+
151+
assert.equal(dump.entries[0]?.url, 'http://localhost:3040/v4/messages/en_US');
152+
});
153+
154+
// Captured from a real iOS simulator app log: `/v4/messages/en_US` opens
155+
// connection 9 and logs its URL, then `/init` reuses connection 9 ~350ms later
156+
// and CFNetwork logs no URL for it anywhere.
157+
const CONNECTION_START =
158+
'2026-09-09 18:22:27.805 Df spicygolf[33656:4505afd] [com.apple.network:connection] [C9 EA66F890-BE05-450D-BF6E-ADE5ADAC1CB8 Hostname#c6f77afc:3040 tcp, url: http://localhost:3040/v4/messages/en_US, definite, attribution: developer] start';
159+
const OPENING_SUMMARY =
160+
'2026-09-09 18:22:27.816 Df spicygolf[33656:4505aed] [com.apple.CFNetwork:Summary] Task <10B2F1BA-8C9E-4877-80D2-994F1C3ED74A>.<1> summary for task success {transaction_duration_ms=11, response_status=200, connection=9, protocol="http/1.1", request_bytes=221, response_bytes=1214, cache_hit=true}';
161+
const REUSED_SUMMARY =
162+
'2026-09-09 18:22:28.167 Df spicygolf[33656:4505ae4] [com.apple.CFNetwork:Summary] Task <2FAEF670-BB27-42A4-ACDD-6B6DF7D11510>.<2> summary for task success {transaction_duration_ms=1, response_status=200, connection=9, reused=1, reused_after_ms=0, request_bytes=236, response_bytes=624, cache_hit=true}';
163+
164+
function iosScan(lines: readonly string[]) {
165+
return readRecentNetworkTrafficFromText(`${lines.join('\n')}\n`, {
166+
path: 'app.log',
167+
exists: true,
168+
backend: 'ios-simulator',
169+
});
170+
}
171+
172+
function iosDump(lines: readonly string[]) {
173+
return iosScan(lines).dump;
174+
}
175+
176+
test('a request that reused a keep-alive connection is reported against its origin', () => {
177+
const dump = iosDump([CONNECTION_START, OPENING_SUMMARY, REUSED_SUMMARY]);
178+
const reused = dump.entries.find((entry) => entry.pathUnavailable);
179+
180+
assert.equal(reused?.url, 'http://localhost:3040');
181+
assert.equal(reused?.status, 200);
182+
assert.equal(reused?.durationMs, 1);
183+
assert.equal(reused?.timestamp, '2026-09-09 18:22:28.167');
184+
});
185+
186+
test('a task that opened its own connection is read from its URL-bearing line only', () => {
187+
const dump = iosDump([CONNECTION_START, OPENING_SUMMARY]);
188+
189+
assert.deepEqual(
190+
dump.entries.map((entry) => entry.url),
191+
['http://localhost:3040/v4/messages/en_US'],
192+
);
193+
assert.equal(dump.entries[0]?.pathUnavailable, undefined);
194+
});
195+
196+
test('a reused request whose connection is outside the scanned window is not invented', () => {
197+
const dump = iosDump([REUSED_SUMMARY]);
198+
199+
assert.deepEqual(dump.entries, []);
200+
});
201+
202+
test('a recycled connection number resolves to the origin most recently opened for it', () => {
203+
const laterStart = CONNECTION_START.replace(
204+
'url: http://localhost:3040/v4/messages/en_US',
205+
'url: https://api.example.test/v1/session',
206+
);
207+
const dump = iosDump([CONNECTION_START, laterStart, REUSED_SUMMARY]);
208+
209+
assert.equal(
210+
dump.entries.find((entry) => entry.pathUnavailable)?.url,
211+
'https://api.example.test',
212+
);
213+
});
214+
215+
test('a reused request that never got a status drops the CFNetwork sentinel', () => {
216+
const failure = REUSED_SUMMARY.replace(
217+
'summary for task success',
218+
'summary for task failure',
219+
).replace('response_status=200', 'response_status=-1');
220+
const dump = iosDump([CONNECTION_START, failure]);
221+
const reused = dump.entries.find((entry) => entry.pathUnavailable);
222+
223+
assert.equal(reused?.url, 'http://localhost:3040');
224+
assert.equal(reused?.status, undefined);
225+
});
226+
227+
test('android dumps do not pay for CFNetwork correlation', () => {
228+
const lines = `${[CONNECTION_START, REUSED_SUMMARY].join('\n')}\n`;
229+
assert.equal(iosDump([CONNECTION_START, REUSED_SUMMARY]).entries.length, 2);
230+
231+
const { dump } = readRecentNetworkTrafficFromText(lines, {
232+
path: 'app.log',
233+
exists: true,
234+
backend: 'android',
235+
});
236+
237+
assert.deepEqual(
238+
dump.entries.map((entry) => entry.url),
239+
['http://localhost:3040/v4/messages/en_US'],
240+
);
241+
assert.equal(dump.unnamedRequests, 0);
242+
});
243+
244+
test('a reused request whose connection opened before the window is counted, not dropped', () => {
245+
const dump = iosDump([REUSED_SUMMARY]);
246+
247+
assert.deepEqual(dump.entries, []);
248+
assert.equal(dump.unnamedRequests, 1);
249+
});
250+
251+
test('a resolved reused request is named, not counted as unnamed', () => {
252+
const dump = iosDump([CONNECTION_START, OPENING_SUMMARY, REUSED_SUMMARY]);
253+
254+
assert.equal(dump.unnamedRequests, 0);
255+
assert.equal(dump.entries.filter((entry) => entry.pathUnavailable).length, 1);
256+
});
257+
258+
function withProcess(line: string, process: string): string {
259+
const swapped = line.replace(/spicygolf\[\d+:[0-9a-f]+\]/, process);
260+
if (swapped === line) throw new Error('fixture process token not found');
261+
return swapped;
262+
}
263+
264+
test('a recycled connection number does not inherit the origin of a previous process', () => {
265+
const relaunchedSummary = REUSED_SUMMARY.replace(
266+
'spicygolf[33656:4505ae4]',
267+
'spicygolf[40001:4505ae4]',
268+
);
269+
const dump = iosDump([CONNECTION_START, relaunchedSummary]);
270+
271+
assert.deepEqual(
272+
dump.entries.filter((entry) => entry.pathUnavailable),
273+
[],
274+
);
275+
assert.equal(dump.unnamedRequests, 1);
276+
});
277+
278+
test('a connection number is resolved within the process that opened it', () => {
279+
const otherProcessStart = withProcess(CONNECTION_START, 'otherapp[40001:4505afd]').replace(
280+
'url: http://localhost:3040/v4/messages/en_US',
281+
'url: https://wrong.example.test/x',
282+
);
283+
const dump = iosDump([otherProcessStart, CONNECTION_START, REUSED_SUMMARY]);
284+
285+
assert.equal(dump.entries.find((entry) => entry.pathUnavailable)?.url, 'http://localhost:3040');
286+
});
287+
288+
test('a line with no readable process identity leaves its traffic unnamed', () => {
289+
const dump = iosDump([
290+
CONNECTION_START.replace('spicygolf[33656:4505afd]', 'spicygolf'),
291+
REUSED_SUMMARY.replace('spicygolf[33656:4505ae4]', 'spicygolf'),
292+
]);
293+
294+
assert.deepEqual(
295+
dump.entries.filter((entry) => entry.pathUnavailable),
296+
[],
297+
);
298+
assert.equal(dump.unnamedRequests, 1);
299+
});
300+
301+
test('a URL whose path ends in punctuation is not truncated into a different endpoint', () => {
302+
const dump = iosDump([
303+
'2026-09-09 18:22:27.805 Df app[1:2] [com.example:Default] GET https://example.test/release. status=200',
304+
]);
305+
306+
assert.equal(dump.entries[0]?.url, 'https://example.test/release.');
307+
});
308+
309+
test('a delimited url: field drops the separator the format put after it', () => {
310+
const dump = iosDump([CONNECTION_START]);
311+
312+
assert.equal(dump.entries[0]?.url, 'http://localhost:3040/v4/messages/en_US');
313+
});
314+
315+
// A second reused request on the same connection, distinct from REUSED_SUMMARY.
316+
const SECOND_REUSED_SUMMARY = REUSED_SUMMARY.replace(
317+
'Task <2FAEF670-BB27-42A4-ACDD-6B6DF7D11510>.<2>',
318+
'Task <9C1D77B4-0E52-4A18-9D31-7F0A2B4C6E88>.<3>',
319+
);
320+
321+
test('two windows over disjoint unnamed traffic report both requests, not the larger count', () => {
322+
const appLog = iosScan([REUSED_SUMMARY]);
323+
const recovery = iosScan([SECOND_REUSED_SUMMARY]);
324+
325+
const merged = mergeNetworkScans(recovery, appLog, 200);
326+
327+
assert.equal(merged.dump.unnamedRequests, 2);
328+
});
329+
330+
test('two windows over the same unnamed request report it once', () => {
331+
const appLog = iosScan([REUSED_SUMMARY, SECOND_REUSED_SUMMARY]);
332+
const recovery = iosScan([SECOND_REUSED_SUMMARY]);
333+
334+
const merged = mergeNetworkScans(recovery, appLog, 200);
335+
336+
assert.equal(merged.dump.unnamedRequests, 2);
337+
});
338+
339+
test('a request one window named is not still counted as unnamed from the other', () => {
340+
const appLog = iosScan([REUSED_SUMMARY]);
341+
const recovery = iosScan([CONNECTION_START, REUSED_SUMMARY]);
342+
343+
assert.equal(appLog.dump.unnamedRequests, 1);
344+
assert.equal(recovery.dump.unnamedRequests, 0);
345+
346+
const merged = mergeNetworkScans(recovery, appLog, 200);
347+
348+
assert.equal(merged.dump.unnamedRequests, 0);
349+
assert.equal(merged.dump.entries.filter((entry) => entry.pathUnavailable).length, 1);
350+
});

0 commit comments

Comments
 (0)