Repository navigation
fix(desktop): skip phx_ keys, keep response bodies out of logs, count duplicate copies #681
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: feat/v6-desktop-capture-v1
Are you sure you want to change the base?
Changes from all commits
823ec66
7e4664d
d515a33
9942076
e790a93
a437bcf
17a72df
7dbc213
c0fd55e
387d936
43acb99
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -28,9 +28,11 @@ class PostHogFetchHttpError implements Exception { | |
| PostHogFetchHttpError(this.status, this.responseBody, this.reqByteLength, | ||
| {this.retryAfter}); | ||
|
|
||
| /// Leaves out [responseBody]: capture's error details can echo request | ||
| /// values. | ||
| @override | ||
| String toString() => 'PostHogFetchHttpError: status=$status, ' | ||
| 'reqByteLength=$reqByteLength, response=$responseBody'; | ||
| 'reqByteLength=$reqByteLength'; | ||
| } | ||
|
|
||
| /// Network error during PostHog fetch. | ||
|
|
@@ -622,7 +624,7 @@ abstract class PostHogCoreStateless { | |
|
|
||
| void _flushBackground(_CaptureLane lane) { | ||
| _flushLane(lane).catchError((e) { | ||
| logger.error('Error while flushing PostHog', e); | ||
| logger.error('Error while flushing PostHog ${lane.path}', e); | ||
| }); | ||
| } | ||
|
|
||
|
|
@@ -748,19 +750,21 @@ abstract class PostHogCoreStateless { | |
| /// delivered or dropped for good. | ||
| /// | ||
| /// A 2xx whose per-event results cannot be read, also when the response | ||
| /// fails after its status arrived, counts as delivered: the server stored | ||
| /// the events, and sending them again would store them twice. | ||
| /// fails after its status arrived, fails the whole batch for good. It | ||
| /// isn't retried: the server may have stored some of the events, and | ||
| /// sending them again would store them twice. | ||
| /// | ||
| /// Throws [PostHogFetchHttpError] for a non-2xx status and | ||
| /// [PostHogFetchNetworkError] for a transport failure. | ||
| /// Throws [PostHogFetchHttpError] for a non-2xx status or an unreadable | ||
| /// 2xx, and [PostHogFetchNetworkError] for a transport failure. | ||
| Future<({Set<String> retryUuids, Duration? retryAfter})> _postCaptureV1( | ||
| _CaptureLane lane, | ||
| List<PostHogQueuedEvent> batch, | ||
| ) async { | ||
| final uuids = { | ||
| final eventUuids = [ | ||
| for (final queued in batch) | ||
| if (queued.event['uuid'] case final String uuid) uuid, | ||
| }; | ||
| ]; | ||
| final uuids = eventUuids.toSet(); | ||
| final pending = lane.pendingIdentity; | ||
| final identity = pending != null && sameUuids(pending.uuids, uuids) | ||
| ? pending.next() | ||
|
|
@@ -791,6 +795,12 @@ abstract class PostHogCoreStateless { | |
| if (response.status < 200 || response.status >= 300) { | ||
| if (!isRetriableCaptureV1Status(response.status)) { | ||
| lane.pendingIdentity = null; | ||
| // A multi-event 413 halves the batch and resends it instead. | ||
| if (response.status != HttpStatus.requestEntityTooLarge || | ||
| batch.length == 1) { | ||
| logger.warn('Capture ${lane.path} returned ${response.status}: ' | ||
| '${batch.length} events dropped for good.'); | ||
| } | ||
| } | ||
| throw PostHogFetchHttpError( | ||
| response.status, | ||
|
|
@@ -800,15 +810,29 @@ abstract class PostHogCoreStateless { | |
| ); | ||
| } | ||
|
|
||
| final results = captureV1Results(response.body, uuids); | ||
| final results = captureV1Results(response.body, eventUuids); | ||
|
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The Linux and Windows desktop integration tests fail with this change: the example app's test server (
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Fixed in 7dbc213 — the test server now answers |
||
| if (results == null) { | ||
| logger.info('Capture returned ${response.status} without readable ' | ||
| 'per-event results; ${uuids.length} events count as delivered.'); | ||
| } else if (results.rejected > 0) { | ||
| logger.warn('Capture dropped ${results.rejected} of ${uuids.length} ' | ||
| 'events for good.'); | ||
| lane.pendingIdentity = null; | ||
| // Status and count only: the body may name event uuids. | ||
| logger.warn('Capture ${lane.path} returned ${response.status} without ' | ||
| 'readable per-event results: ${batch.length} events dropped for ' | ||
| 'good.'); | ||
| throw PostHogFetchHttpError(response.status, '', body.length); | ||
| } | ||
| // Counts and the server's opaque reasons only, one line per batch: | ||
| // uuids and event content can identify users. | ||
| final dropped = results.drops.values.fold(0, (sum, n) => sum + n); | ||
| if (dropped > 0 || results.duplicates > 0) { | ||
| final reasons = [ | ||
| for (final MapEntry(:key, :value) in results.drops.entries) | ||
| '$key: $value', | ||
| ].join(', '); | ||
| logger.warn('Capture ${lane.path} dropped $dropped of ' | ||
| '${batch.length} events for good' | ||
| '${reasons.isEmpty ? '' : ' ($reasons)'}' | ||
|
turnipdabeets marked this conversation as resolved.
Resolved
|
||
| ' and ${results.duplicates} repeated-uuid copies.'); | ||
| } | ||
| final retryUuids = results?.retry ?? const <String>{}; | ||
| final retryUuids = results.retry; | ||
| lane.pendingIdentity = | ||
| retryUuids.isEmpty ? null : identity.withUuids(retryUuids); | ||
| return (retryUuids: retryUuids, retryAfter: response.retryAfter); | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -154,6 +154,16 @@ void main() { | |
| expect(lines.single, contains('number')); | ||
| expect(lines.single, isNot(contains('42'))); | ||
| }); | ||
|
|
||
| test('names the JSON type of a boolean session id', () { | ||
| final lines = <String>[]; | ||
| captureV1Event({ | ||
| 'event': 'e', | ||
| 'properties': {r'$window_id': true}, | ||
| }, CoreLogger((log) => lines.addAll(printedLines(log)))); | ||
|
|
||
| expect(lines.single, contains('a boolean value')); | ||
| }); | ||
| }); | ||
|
|
||
| group('captureRetryDelay', () { | ||
|
|
@@ -228,8 +238,10 @@ void main() { | |
| final uuids = [ | ||
| for (final event in api.batchRequests.single.events) event['uuid'], | ||
| ]; | ||
| final rejection = | ||
| lines.singleWhere((line) => line.contains('dropped 2 of 7')); | ||
| // `limited` and unknown results count as delivered, like `ok`. | ||
| final rejection = lines.singleWhere((line) => line | ||
| .contains('/i/v1/analytics/events dropped 1 of 7 events for good ' | ||
| '(detail: 1)')); | ||
| for (final uuid in uuids) { | ||
| expect(rejection, isNot(contains('$uuid'))); | ||
| } | ||
|
|
@@ -359,18 +371,109 @@ void main() { | |
| }); | ||
| }); | ||
|
|
||
| test('counts a 2xx without readable results as delivered', () async { | ||
| test('counts the duplicate copies capture dropped', () { | ||
| final body = jsonEncode({ | ||
| 'results': { | ||
| 'a': {'result': 'ok', 'duplicates_dropped': 2}, | ||
| 'b': {'result': 'retry', 'duplicates_dropped': 1}, | ||
| 'c': {'result': 'ok'}, | ||
| }, | ||
| }); | ||
|
|
||
| final results = captureV1Results(body, ['a', 'b', 'c'])!; | ||
|
|
||
| expect(results.duplicates, 3); | ||
| expect(results.retry, {'b'}); | ||
| }); | ||
|
|
||
| test('clamps malformed duplicates_dropped to the batch size', () { | ||
| final body = jsonEncode({ | ||
| 'results': { | ||
| 'a': {'result': 'ok', 'duplicates_dropped': 9007199254740991}, | ||
| 'b': {'result': 'ok', 'duplicates_dropped': -5}, | ||
| 'c': {'result': 'ok', 'duplicates_dropped': '2'}, | ||
| }, | ||
| }); | ||
|
|
||
| expect(captureV1Results(body, ['a', 'b', 'c'])!.duplicates, 3); | ||
| }); | ||
|
|
||
| test('clamps duplicates_dropped against every copy sent', () { | ||
| final body = jsonEncode({ | ||
| 'results': { | ||
| 'a': {'result': 'drop', 'duplicates_dropped': 2}, | ||
| }, | ||
| }); | ||
|
|
||
| final results = captureV1Results(body, ['a', 'a', 'a'])!; | ||
|
|
||
| expect(results.duplicates, 2); | ||
| expect(results.drops, {'no details': 1}); | ||
| }); | ||
|
|
||
| test('keeps only reason codes as drop reasons', () { | ||
| final body = jsonEncode({ | ||
| 'results': { | ||
| 'a': {'result': 'drop', 'details': 'event_too_big'}, | ||
| 'b': {'result': 'drop', 'details': 'x\n[PostHog] forged'}, | ||
| 'c': {'result': 'drop', 'details': '[email protected]'}, | ||
| 'd': {'result': 'drop', 'details': 'a' * 65}, | ||
| }, | ||
| }); | ||
|
|
||
| expect(captureV1Results(body, ['a', 'b', 'c', 'd'])!.drops, { | ||
| 'event_too_big': 1, | ||
| 'no details': 3, | ||
| }); | ||
| }); | ||
|
|
||
| test('drops a 2xx without readable results without retrying it', () async { | ||
| final server = await LocalPostHogServer.start(); | ||
| final storage = tempStorage(); | ||
| final client = testClient(server, storage: storage); | ||
| server.respond = | ||
| (_) => const PostHogResponse(HttpStatus.ok, body: 'not json'); | ||
| final errors = <Object?>[]; | ||
| // ignore: invalid_use_of_protected_member | ||
| client.events.on('error', errors.add); | ||
| final flushed = <Object?>[]; | ||
| // ignore: invalid_use_of_protected_member | ||
| client.events.on('flush', flushed.add); | ||
|
|
||
| client.capture('evt'); | ||
| await client.flush(); | ||
| await expectLater(client.flush(), throwsA(isA<PostHogFetchHttpError>())); | ||
|
|
||
| expect(server.batchRequests, hasLength(1)); | ||
| expect(getQueue(storage), isEmpty); | ||
| expect(errors, hasLength(1)); | ||
| expect(flushed, isEmpty); | ||
| }); | ||
|
|
||
| test('logs the endpoint and count of a batch lost to a terminal status', | ||
| () { | ||
| final api = InProcessPostHogApi(); | ||
| final storage = tempStorage(); | ||
| fakeAsync((async) { | ||
| final client = | ||
| testClient(api, config: testConfig(debug: true), storage: storage); | ||
| api.respond = (request) => request.isFlags | ||
| ? PostHogResponse.json({'flags': <String, Object?>{}}) | ||
| : const PostHogResponse(HttpStatus.badRequest); | ||
| client.capture('one'); | ||
| client.capture('two'); | ||
|
|
||
| final lines = printedLines(() { | ||
| client.flush().catchError((_) {}); | ||
| async.elapse(Duration.zero); | ||
| }); | ||
|
|
||
| expect(api.batchRequests, hasLength(1)); | ||
| expect(queuedEvents(storage), isEmpty); | ||
| expect( | ||
| lines, | ||
| contains(contains('Capture /i/v1/analytics/events returned 400: ' | ||
| '2 events dropped for good.'))); | ||
| }); | ||
| }); | ||
|
|
||
| test('drops a single event that is still too large', () async { | ||
|
|
@@ -419,7 +522,7 @@ void main() { | |
| server.respond = (request) => request.path == '/i/v1/analytics/events' | ||
| ? PostHogResponse(HttpStatus.temporaryRedirect, | ||
| location: '${server.url}/moved/events') | ||
| : const PostHogResponse(HttpStatus.ok); | ||
| : PostHogResponse.results(request, (_) => 'ok'); | ||
|
|
||
| client.capture('evt'); | ||
| await client.flush(); | ||
|
|
||
Uh oh!
There was an error while loading. Please reload this page.