From 248e7642c3adefa17df72cbe6def9fb5f4283443 Mon Sep 17 00:00:00 2001 From: Mohanned Binmiskeen Date: Mon, 3 Aug 2026 19:21:29 +0200 Subject: [PATCH] fix: log redaction, registration race, and incomplete reset Fixes #9, #10 and #11. The three touch overlapping files, so they land together. #9 - credentials and PII in the logs (enableLogging: true only) Three sites wrote secrets verbatim: device_service.dart logged Device.toJson(), which carries the full FCM token; subscriber_service logged the login payload - name, email, phone, metadata; tag_service logged tag values, which routinely hold an email, plan or region. Every request body also reached logApiRequest verbatim, repeating the same values at debug level. Adds PushFireLogger.redact, applied to device info and to request and response bodies. The token keeps the existing first/last-ten mask so it stays correlatable with the server; everything else becomes . Identifiers - externalId, deviceId, subscriberId, tagId - are left alone: they are what a support ticket is traced by. Response bodies are redacted too, since register-device returns the device row and login-subscriber the subscriber row; a body that is not a JSON object passes through unchanged. #10 - registerDevice had no concurrency guard registerDevice reads the stored device id, makes a network round trip, then writes the id back. Two callers entering before either wrote both saw no id, both POSTed, and created two device rows for one device. The second write won locally, so the first row was orphaned server-side while still holding the same FCM token. Reachable from auto-registration at init, the token-refresh handler, the foreground permission check and requestNotificationPermission. registerDevice is now single-flight: concurrent callers join the in-flight registration. The guard is released on failure too, so a failed attempt does not wedge later callers. The permission check is coalesced the same way. The old _isCheckingPermission flag guarded only the resume path, so a token refresh arriving during a resume ran two overlapping checks; both syncNotificationPermission and the token-refresh handler now go through it. Callers that join receive null, so one permission change still emits exactly one onDeviceRegistered. #11 - reset() could leave state behind Two failure modes. A stored subscriber blob whose id is null does not count as logged in, so the gated logout skipped it and the blob - name, email, phone - survived a call documented as clearing all local state; on a shared device the next user's session started holding the previous user's details. And logoutSubscriber clears locally then rethrows, so a failed logout request propagated out of reset() and clearDeviceData() never ran, leaving the device id, FCM token and permission state behind. Both clears are now unconditional and run after a logout that cannot escape. clearSubscriberData is public for that; the teardown is extracted as clearAllLocalState so it can be tested without a live SDK singleton, which needs Firebase. 28 regression tests. Each was checked to fail with its fix reverted. --- lib/src/pushfire_sdk_impl.dart | 114 +++++++--- lib/src/services/device_service.dart | 41 +++- lib/src/services/subscriber_service.dart | 11 +- lib/src/services/tag_service.dart | 5 +- lib/src/utils/logger.dart | 94 +++++++- test/pushfire_sdk_reset_test.dart | 170 ++++++++++++++ ..._service_concurrent_registration_test.dart | 162 ++++++++++++++ test/services/service_logging_pii_test.dart | 116 ++++++++++ test/utils/logger_redaction_test.dart | 208 ++++++++++++++++++ 9 files changed, 877 insertions(+), 44 deletions(-) create mode 100644 test/pushfire_sdk_reset_test.dart create mode 100644 test/services/device_service_concurrent_registration_test.dart create mode 100644 test/services/service_logging_pii_test.dart create mode 100644 test/utils/logger_redaction_test.dart diff --git a/lib/src/pushfire_sdk_impl.dart b/lib/src/pushfire_sdk_impl.dart index 21c2986..3d12f68 100644 --- a/lib/src/pushfire_sdk_impl.dart +++ b/lib/src/pushfire_sdk_impl.dart @@ -1,5 +1,6 @@ import 'dart:async'; -import 'package:flutter/foundation.dart' show debugPrint, kIsWeb; +import 'package:flutter/foundation.dart' + show debugPrint, kIsWeb, visibleForTesting; import 'package:flutter/widgets.dart'; import 'package:firebase_auth/firebase_auth.dart' show FirebaseAuth, User; import 'package:firebase_core/firebase_core.dart'; @@ -47,8 +48,9 @@ class PushFireSDKImpl with WidgetsBindingObserver { StreamSubscription? _supabaseAuthSubscription; StreamSubscription? _firebaseAuthSubscription; - // Flag to prevent overlapping permission checks - bool _isCheckingPermission = false; + // The permission check currently in flight, if any. Concurrent callers join + // it rather than starting a second one. See _guardedPermissionCheck. + Future? _permissionCheck; PushFireSDKImpl._(); @@ -232,8 +234,13 @@ class PushFireSDKImpl with WidgetsBindingObserver { PushFireLogger.info('FCM token refreshed'); PushFireLogger.logFcmToken(newToken); - // Check for permission status changes before re-registering - await _deviceService.checkAndHandlePermissionStatusChange(); + // Check for permission status changes before re-registering, through + // the same guard the resume path uses: a token refresh arriving during + // a foreground resume would otherwise run two overlapping checks. + // The result is deliberately ignored — the registerDevice() below + // already emits onDeviceRegistered for this refresh, and emitting here + // too would produce two events for one logical change. + await _guardedPermissionCheck(); // Re-register device with new token _currentDevice = await _deviceService.registerDevice(); @@ -269,22 +276,45 @@ class PushFireSDKImpl with WidgetsBindingObserver { } } + /// Run the permission-change check under the overlap guard shared by every + /// caller — the foreground resume, the FCM token-refresh handler and + /// [syncNotificationPermission]. + /// + /// A caller that arrives while a check is running joins it rather than + /// starting a second one, and receives null: the owner of the check reports + /// the change, so one permission change produces exactly one event no matter + /// how many callers are waiting. + /// + /// Returns the re-registered device when this caller's check synced a + /// change, null otherwise. + Future _guardedPermissionCheck() { + final existing = _permissionCheck; + if (existing != null) { + PushFireLogger.info('Permission check already in progress - joining it'); + return existing.then((_) => null); + } + + final check = _runPermissionCheck(); + _permissionCheck = check; + return check; + } + + /// Wraps the check so the guard is released on both success and failure. + Future _runPermissionCheck() async { + try { + return await _deviceService.checkAndHandlePermissionStatusChange(); + } finally { + _permissionCheck = null; + } + } + /// Check permission status when app resumes /// This method is safe to call multiple times - it guards against overlapping executions Future _checkPermissionStatusOnResume() async { - // Prevent overlapping calls - if a check is already in progress, skip this one - if (_isCheckingPermission) { - PushFireLogger.info( - 'Permission check already in progress - skipping duplicate call'); - return; - } - - _isCheckingPermission = true; try { PushFireLogger.info( 'App resumed - checking notification permission status'); - final updatedDevice = - await _deviceService.checkAndHandlePermissionStatusChange(); + final updatedDevice = await _guardedPermissionCheck(); if (updatedDevice != null) { // Device was already re-registered by checkAndHandlePermissionStatusChange @@ -296,8 +326,6 @@ class PushFireSDKImpl with WidgetsBindingObserver { } catch (e) { PushFireLogger.warning( 'Failed to check permission status on app resume', e); - } finally { - _isCheckingPermission = false; } } @@ -548,7 +576,7 @@ class PushFireSDKImpl with WidgetsBindingObserver { /// Returns the current [NotificationStatus] after syncing. Future syncNotificationPermission() async { _ensureInitialized(); - final device = await _deviceService.checkAndHandlePermissionStatusChange(); + final device = await _guardedPermissionCheck(); if (device != null) { _currentDevice = device; _deviceRegisteredController.add(device); @@ -590,13 +618,12 @@ class PushFireSDKImpl with WidgetsBindingObserver { PushFireLogger.info('Resetting SDK'); - // Logout subscriber if logged in - if (await isSubscriberLoggedIn()) { - await logoutSubscriber(); - } - - // Clear device data - await _deviceService.clearDeviceData(); + await clearAllLocalState( + subscriberService: _subscriberService, + deviceService: _deviceService, + isSubscriberLoggedIn: isSubscriberLoggedIn, + logoutSubscriber: logoutSubscriber, + ); // Reset current state _currentDevice = null; @@ -605,6 +632,39 @@ class PushFireSDKImpl with WidgetsBindingObserver { PushFireLogger.info('SDK reset completed'); } + /// The local-state teardown performed by [reset]. + /// + /// Extracted so it can be tested without a live SDK singleton, which needs + /// Firebase. + /// + /// Both clears are unconditional and run after a logout that cannot escape: + /// + /// - A stored subscriber blob whose `id` is null does not count as logged in, + /// so the gated logout skips it and the blob — name, email, phone — would + /// survive a call that documents itself as clearing all local state. + /// - `logoutSubscriber` clears locally and then rethrows when the server call + /// fails. Letting that escape would skip [DeviceService.clearDeviceData], + /// leaving the device id, FCM token and permission state behind. + @visibleForTesting + static Future clearAllLocalState({ + required SubscriberService subscriberService, + required DeviceService deviceService, + required Future Function() isSubscriberLoggedIn, + required Future Function() logoutSubscriber, + }) async { + try { + if (await isSubscriberLoggedIn()) { + await logoutSubscriber(); + } + } catch (e) { + PushFireLogger.warning( + 'Logout during reset failed - clearing local state anyway', e); + } + + await subscriberService.clearSubscriberData(); + await deviceService.clearDeviceData(); + } + /// Dispose SDK resources void dispose() { if (!_isInitialized) return; @@ -618,8 +678,8 @@ class PushFireSDKImpl with WidgetsBindingObserver { // Ignore if observer wasn't added or WidgetsBinding is not available } - // Reset flags - _isCheckingPermission = false; + // Drop the in-flight permission check, if any + _permissionCheck = null; // Cancel stream subscriptions to prevent memory leaks _fcmTokenRefreshSubscription?.cancel(); diff --git a/lib/src/services/device_service.dart b/lib/src/services/device_service.dart index c8718c0..54a9a4a 100644 --- a/lib/src/services/device_service.dart +++ b/lib/src/services/device_service.dart @@ -42,8 +42,45 @@ class DeviceService { this.openAppSettingsOverride, }); - /// Register or update device automatically - Future registerDevice() async { + /// The registration currently in flight, if any. See [registerDevice]. + Future? _inFlightRegistration; + + /// Register or update device automatically. + /// + /// Single-flight: registration reads the stored device id, makes a network + /// round trip, then writes the id back. Two callers entering before either + /// writes would both see no stored id, both POST, and create two device rows + /// for one device — the second write wins locally, orphaning the first row + /// server-side while it still holds the same FCM token. Concurrent callers + /// therefore join the in-flight registration instead of starting a second. + /// + /// Reachable concurrently from auto-registration at init, the FCM + /// token-refresh handler, the foreground permission check, and + /// [requestNotificationPermission]. + Future registerDevice() { + final existing = _inFlightRegistration; + if (existing != null) { + PushFireLogger.info( + 'Device registration already in progress - joining it'); + return existing; + } + + final registration = _runRegistration(); + _inFlightRegistration = registration; + return registration; + } + + /// Wraps [_performRegistration] so the guard is released on both success and + /// failure — a failed attempt must not wedge every later caller. + Future _runRegistration() async { + try { + return await _performRegistration(); + } finally { + _inFlightRegistration = null; + } + } + + Future _performRegistration() async { try { PushFireLogger.info('Starting device registration'); diff --git a/lib/src/services/subscriber_service.dart b/lib/src/services/subscriber_service.dart index c72fd33..6ea2c70 100644 --- a/lib/src/services/subscriber_service.dart +++ b/lib/src/services/subscriber_service.dart @@ -47,7 +47,8 @@ class SubscriberService { }, }; - PushFireLogger.info('Logging in subscriber with data: $subscriberData'); + PushFireLogger.info( + 'Logging in subscriber with data: ${PushFireLogger.redact(subscriberData)}'); // Make API call final response = @@ -147,7 +148,7 @@ class SubscriberService { if (subscriber?.id == null || deviceId == null) { PushFireLogger.warning('No subscriber or device found for logout'); - await _clearSubscriberData(); + await clearSubscriberData(); return; } @@ -162,7 +163,7 @@ class SubscriberService { await _apiClient.post('logout-subscriber', logoutData); // Clear local data - await _clearSubscriberData(); + await clearSubscriberData(); PushFireLogger.info('Subscriber logout completed'); } catch (e) { @@ -170,7 +171,7 @@ class SubscriberService { // methods) is deliberate: local data must be cleared on BOTH expected // and unexpected failures. Clear first, then rethrow PushFireExceptions // (already logged downstream) or wrap-and-log genuinely unexpected ones. - await _clearSubscriberData(); + await clearSubscriberData(); if (e is PushFireException) { rethrow; @@ -221,7 +222,7 @@ class SubscriberService { } /// Clear subscriber data from local storage - Future _clearSubscriberData() async { + Future clearSubscriberData() async { final prefs = await SharedPreferences.getInstance(); await prefs.remove(_subscriberIdKey); await prefs.remove(_subscriberDataKey); diff --git a/lib/src/services/tag_service.dart b/lib/src/services/tag_service.dart index c2ad734..b9e6c1f 100644 --- a/lib/src/services/tag_service.dart +++ b/lib/src/services/tag_service.dart @@ -14,7 +14,8 @@ class TagService { /// Add a tag to the current subscriber Future addTag(String tagId, String value) async { try { - PushFireLogger.info('Adding tag: $tagId = $value'); + // Value omitted: tag values routinely hold an email, plan or region. + PushFireLogger.info('Adding tag: $tagId'); // Get current subscriber ID final subscriberId = await _subscriberService.getSubscriberId(); @@ -59,7 +60,7 @@ class TagService { /// Update a tag value for the current subscriber Future updateTag(String tagId, String value) async { try { - PushFireLogger.info('Updating tag: $tagId = $value'); + PushFireLogger.info('Updating tag: $tagId'); // Get current subscriber ID final subscriberId = await _subscriberService.getSubscriberId(); diff --git a/lib/src/utils/logger.dart b/lib/src/utils/logger.dart index ed1a1bc..97a8827 100644 --- a/lib/src/utils/logger.dart +++ b/lib/src/utils/logger.dart @@ -1,3 +1,4 @@ +import 'dart:convert'; import 'dart:developer' as developer; import 'package:flutter/foundation.dart' show visibleForTesting; import 'package:logging/logging.dart'; @@ -59,13 +60,90 @@ class PushFireLogger { } } + /// Keys whose values must never reach a log line: the FCM token, which is a + /// send capability, and subscriber PII. + /// + /// Both casings are listed because the SDK sends camelCase but the server may + /// echo snake_case back. + static const Set _sensitiveKeys = { + 'fcmToken', + 'fcm_token', + 'name', + 'email', + 'phone', + 'metadata', + // Tag values routinely hold an email, plan or region. + 'value', + }; + + static const String _redacted = ''; + + /// Copy [body] with every credential and PII value replaced. + /// + /// The shape survives — which keys were sent, and a masked token that can + /// still be correlated with the server — so the log stays useful for + /// debugging without carrying the values themselves into device logs, which + /// other tooling and crash collectors read. + static Map redact(Map body) { + final result = {}; + body.forEach((key, value) { + result[key] = _sensitiveKeys.contains(key) + ? _maskSensitive(key, value) + : _redactNested(value); + }); + return result; + } + + static Object? _maskSensitive(String key, Object? value) { + if (value == null) return null; + if (value is String && (key == 'fcmToken' || key == 'fcm_token')) { + return maskToken(value); + } + return _redacted; + } + + static Object? _redactNested(Object? value) { + if (value is Map) { + return redact(value.map((k, v) => MapEntry(k.toString(), v))); + } + if (value is List) { + return value.map(_redactNested).toList(); + } + return value; + } + + /// Mask a token, keeping enough of each end to correlate it with the server. + @visibleForTesting + static String maskToken(String token) { + return token.length > 20 + ? '${token.substring(0, 10)}...${token.substring(token.length - 10)}' + : token; + } + + /// Redact a raw JSON response body. + /// + /// Anything that is not a JSON object — an HTML gateway page, a plain string + /// — is returned unchanged: it carries no field the SDK sent. + @visibleForTesting + static String redactBody(String body) { + try { + final decoded = json.decode(body); + if (decoded is Map) { + return json.encode(redact(decoded)); + } + } catch (_) { + // Not JSON; fall through. + } + return body; + } + /// Log API request static void logApiRequest( String method, String url, Map? body) { if (_enableLogging) { final message = 'API Request: $method $url'; if (body != null) { - debug('$message\nBody: $body'); + debug('$message\nBody: ${redact(body)}'); } else { debug(message); } @@ -78,7 +156,9 @@ class PushFireLogger { if (_enableLogging) { final message = 'API Response: $method $url - Status: $statusCode'; if (body != null && body.isNotEmpty) { - debug('$message\nResponse: $body'); + // Responses echo back what was sent: register-device returns the device + // row, login-subscriber the subscriber row. + debug('$message\nResponse: ${redactBody(body)}'); } else { debug(message); } @@ -115,20 +195,18 @@ class PushFireLogger { } /// Log device information + /// + /// The map is a `Device.toJson()`, which carries the full FCM token. static void logDeviceInfo(Map deviceInfo) { if (_enableLogging) { - info('Device Info: $deviceInfo'); + info('Device Info: ${redact(deviceInfo)}'); } } /// Log FCM token static void logFcmToken(String token) { if (_enableLogging) { - // Only log first and last 10 characters for security - final maskedToken = token.length > 20 - ? '${token.substring(0, 10)}...${token.substring(token.length - 10)}' - : token; - info('FCM Token: $maskedToken'); + info('FCM Token: ${maskToken(token)}'); } } diff --git a/test/pushfire_sdk_reset_test.dart b/test/pushfire_sdk_reset_test.dart new file mode 100644 index 0000000..33534d4 --- /dev/null +++ b/test/pushfire_sdk_reset_test.dart @@ -0,0 +1,170 @@ +import 'dart:convert'; + +import 'package:flutter_test/flutter_test.dart'; +import 'package:shared_preferences/shared_preferences.dart'; +import 'package:pushfire_sdk/src/api/pushfire_api_client.dart'; +import 'package:pushfire_sdk/src/config/pushfire_config.dart'; +import 'package:pushfire_sdk/src/exceptions/pushfire_exceptions.dart'; +import 'package:pushfire_sdk/src/pushfire_sdk_impl.dart'; +import 'package:pushfire_sdk/src/services/device_service.dart'; +import 'package:pushfire_sdk/src/services/subscriber_service.dart'; + +class FakeApiClient extends PushFireApiClient { + final List postEndpoints = []; + Object? postError; + + FakeApiClient() + : super(const PushFireConfig(apiKey: 'k', baseUrl: 'http://test/')); + + @override + Future> post( + String endpoint, Map data) async { + postEndpoints.add(endpoint); + if (postError != null) throw postError!; + return {'success': true}; + } +} + +const _subscriberIdKey = 'pushfire_subscriber_id'; +const _subscriberDataKey = 'pushfire_subscriber_data'; +const _deviceIdKey = 'pushfire_device_id'; +const _fcmTokenKey = 'pushfire_fcm_token'; +const _lastPermissionStatusKey = 'pushfire_last_permission_status'; +const _notificationPreferenceKey = 'pushfire_notification_preference'; + +/// Everything reset() promises to erase. +const _allKeys = [ + _subscriberIdKey, + _subscriberDataKey, + _deviceIdKey, + _fcmTokenKey, + _lastPermissionStatusKey, + _notificationPreferenceKey, +]; + +Map _seed({required Map subscriberBlob}) => { + _subscriberDataKey: json.encode(subscriberBlob), + if (subscriberBlob['id'] != null) + _subscriberIdKey: subscriberBlob['id'] as String, + _deviceIdKey: 'dev-abc', + _fcmTokenKey: 'fcm-token', + _lastPermissionStatusKey: true, + _notificationPreferenceKey: false, + }; + +/// A fully populated subscriber, as stored after a successful login. +const _loggedIn = { + 'id': 'sub-123', + 'deviceId': 'dev-abc', + 'externalId': 'user-1', + 'name': 'Ada Lovelace', + 'email': 'ada@example.com', + 'phone': '+15551234567', +}; + +Future _expectEverythingCleared() async { + final prefs = await SharedPreferences.getInstance(); + for (final key in _allKeys) { + expect(prefs.get(key), isNull, reason: '$key survived the reset'); + } +} + +void main() { + TestWidgetsFlutterBinding.ensureInitialized(); + + late FakeApiClient api; + late DeviceService deviceService; + late SubscriberService subscriberService; + + void wire() { + api = FakeApiClient(); + deviceService = DeviceService( + api, + const PushFireConfig(apiKey: 'k', baseUrl: 'http://test/'), + ); + subscriberService = SubscriberService(api, deviceService); + } + + Future reset() => PushFireSDKImpl.clearAllLocalState( + subscriberService: subscriberService, + deviceService: deviceService, + isSubscriberLoggedIn: subscriberService.isSubscriberLoggedIn, + logoutSubscriber: subscriberService.logoutSubscriber, + ); + + group('reset clears all local state', () { + test('logs out and clears everything on the happy path', () async { + SharedPreferences.setMockInitialValues(_seed(subscriberBlob: _loggedIn)); + wire(); + + await reset(); + + expect(api.postEndpoints, ['logout-subscriber']); + await _expectEverythingCleared(); + }); + + test('clears a stored subscriber whose id is null', () async { + // A blob with no id does not count as logged in, so the gated logout + // skips it entirely — and on a shared device the next user's session + // would start holding the previous user's name, email and phone. + SharedPreferences.setMockInitialValues(_seed(subscriberBlob: { + 'deviceId': 'dev-abc', + 'externalId': 'user-1', + 'name': 'Ada Lovelace', + 'email': 'ada@example.com', + 'phone': '+15551234567', + })); + wire(); + + expect(await subscriberService.isSubscriberLoggedIn(), isFalse); + + await reset(); + + expect(api.postEndpoints, isEmpty, reason: 'nothing to log out'); + await _expectEverythingCleared(); + }); + + test('clears device data when the logout request fails', () async { + // logoutSubscriber clears locally and then rethrows. Letting that escape + // skipped clearDeviceData, so the device id, FCM token and permission + // state survived a reset that reported failure. + SharedPreferences.setMockInitialValues(_seed(subscriberBlob: _loggedIn)); + wire(); + api.postError = const PushFireApiException('boom', statusCode: 500); + + await reset(); + + expect(api.postEndpoints, ['logout-subscriber']); + await _expectEverythingCleared(); + }); + + test('does not rethrow a failed logout', () async { + SharedPreferences.setMockInitialValues(_seed(subscriberBlob: _loggedIn)); + wire(); + api.postError = const PushFireNetworkException('offline'); + + await expectLater(reset(), completes); + }); + + test('clears device data when the logout throws something unexpected', + () async { + SharedPreferences.setMockInitialValues(_seed(subscriberBlob: _loggedIn)); + wire(); + api.postError = StateError('not a PushFireException'); + + await reset(); + + await _expectEverythingCleared(); + }); + + test('is a no-op on an already clean install', () async { + SharedPreferences.setMockInitialValues({}); + wire(); + + await reset(); + + expect(api.postEndpoints, isEmpty); + await _expectEverythingCleared(); + }); + }); +} diff --git a/test/services/device_service_concurrent_registration_test.dart b/test/services/device_service_concurrent_registration_test.dart new file mode 100644 index 0000000..fe6a605 --- /dev/null +++ b/test/services/device_service_concurrent_registration_test.dart @@ -0,0 +1,162 @@ +import 'package:flutter_test/flutter_test.dart'; +import 'package:shared_preferences/shared_preferences.dart'; +import 'package:pushfire_sdk/src/api/pushfire_api_client.dart'; +import 'package:pushfire_sdk/src/config/pushfire_config.dart'; +import 'package:pushfire_sdk/src/exceptions/pushfire_exceptions.dart'; +import 'package:pushfire_sdk/src/services/device_service.dart'; + +/// API client that records calls and can hold a POST open, so two callers are +/// genuinely in flight at the same time. +class SlowFakeApiClient extends PushFireApiClient { + final List postEndpoints = []; + final List patchEndpoints = []; + Duration postDelay = const Duration(milliseconds: 20); + int _nextDeviceId = 1; + + SlowFakeApiClient() + : super(const PushFireConfig(apiKey: 'test', baseUrl: 'http://test/')); + + @override + Future> post( + String endpoint, Map data) async { + postEndpoints.add(endpoint); + await Future.delayed(postDelay); + // A distinct id per call, so a second registration is visible in the + // returned device rather than hidden behind a shared constant. + return {'id': 'device-${_nextDeviceId++}'}; + } + + @override + Future> patch( + String endpoint, Map data) async { + patchEndpoints.add(endpoint); + await Future.delayed(postDelay); + return {'success': true}; + } +} + +const _deviceInfo = { + 'os': 'ios', + 'osVersion': '17.0', + 'language': 'en', + 'manufacturer': 'Apple', + 'model': 'iPhone', + 'appVersion': '1.0.0', +}; + +void main() { + TestWidgetsFlutterBinding.ensureInitialized(); + + group('registerDevice is single-flight', () { + setUp(() => SharedPreferences.setMockInitialValues({})); + + test('two concurrent callers create one device row', () async { + final api = SlowFakeApiClient(); + final service = DeviceService( + api, + const PushFireConfig(apiKey: 'test', baseUrl: 'http://test/'), + isPushNotificationEnabledOverride: () async => true, + getDeviceInfoOverride: () async => _deviceInfo, + getFcmTokenOverride: () async => 'fcm-token', + ); + + // Both enter before either writes the device id. Without the guard both + // read no stored id, both POST, and the first row is orphaned server-side + // while still holding this FCM token. + final results = await Future.wait([ + service.registerDevice(), + service.registerDevice(), + ]); + + expect(api.postEndpoints, ['register-device']); + expect(results[0].id, results[1].id); + + final prefs = await SharedPreferences.getInstance(); + expect(prefs.getString('pushfire_device_id'), results[0].id); + }); + + test('five concurrent callers still create one device row', () async { + final api = SlowFakeApiClient(); + final service = DeviceService( + api, + const PushFireConfig(apiKey: 'test', baseUrl: 'http://test/'), + isPushNotificationEnabledOverride: () async => true, + getDeviceInfoOverride: () async => _deviceInfo, + getFcmTokenOverride: () async => 'fcm-token', + ); + + final results = await Future.wait( + List.generate(5, (_) => service.registerDevice()), + ); + + expect(api.postEndpoints.length, 1); + expect(results.map((d) => d.id).toSet(), {results.first.id}); + }); + + test('a later registration is not blocked by an earlier finished one', + () async { + final api = SlowFakeApiClient(); + var token = 'token-1'; + final service = DeviceService( + api, + const PushFireConfig(apiKey: 'test', baseUrl: 'http://test/'), + isPushNotificationEnabledOverride: () async => true, + getDeviceInfoOverride: () async => _deviceInfo, + getFcmTokenOverride: () async => token, + ); + + await service.registerDevice(); + // The token rotated, so the second call must reach the server — the guard + // coalesces concurrent callers, it does not cache the result. + token = 'token-2'; + await service.registerDevice(); + + expect(api.postEndpoints, ['register-device']); + expect(api.patchEndpoints, ['update-device']); + }); + + test('a failed registration releases the guard', () async { + final api = SlowFakeApiClient(); + String? token; + final service = DeviceService( + api, + const PushFireConfig(apiKey: 'test', baseUrl: 'http://test/'), + isPushNotificationEnabledOverride: () async => true, + getDeviceInfoOverride: () async => _deviceInfo, + getFcmTokenOverride: () async => token, + ); + + // No FCM token yet — registration fails, as it does on a cold iOS start + // before APNS answers. + await expectLater( + service.registerDevice(), + throwsA(isA()), + ); + + // The token arrives via onTokenRefresh. A wedged guard would hand this + // caller the earlier failure forever. + token = 'fcm-token'; + final device = await service.registerDevice(); + + expect(device.id, isNotNull); + expect(api.postEndpoints, ['register-device']); + }); + + test('concurrent callers all see the failure', () async { + final api = SlowFakeApiClient(); + final service = DeviceService( + api, + const PushFireConfig(apiKey: 'test', baseUrl: 'http://test/'), + isPushNotificationEnabledOverride: () async => true, + getDeviceInfoOverride: () async => _deviceInfo, + getFcmTokenOverride: () async => null, + ); + + final first = service.registerDevice(); + final second = service.registerDevice(); + + await expectLater(first, throwsA(isA())); + await expectLater(second, throwsA(isA())); + }); + }); +} diff --git a/test/services/service_logging_pii_test.dart b/test/services/service_logging_pii_test.dart new file mode 100644 index 0000000..8bddc5f --- /dev/null +++ b/test/services/service_logging_pii_test.dart @@ -0,0 +1,116 @@ +import 'dart:convert'; + +import 'package:flutter_test/flutter_test.dart'; +import 'package:logging/logging.dart'; +import 'package:shared_preferences/shared_preferences.dart'; +import 'package:pushfire_sdk/src/api/pushfire_api_client.dart'; +import 'package:pushfire_sdk/src/config/pushfire_config.dart'; +import 'package:pushfire_sdk/src/models/subscriber.dart'; +import 'package:pushfire_sdk/src/services/device_service.dart'; +import 'package:pushfire_sdk/src/services/subscriber_service.dart'; +import 'package:pushfire_sdk/src/services/tag_service.dart'; +import 'package:pushfire_sdk/src/utils/logger.dart'; + +/// What the services log while doing real work, not what the redaction helper +/// does in isolation. +class FakeApiClient extends PushFireApiClient { + FakeApiClient() + : super(const PushFireConfig(apiKey: 'k', baseUrl: 'http://test/')); + + @override + Future> post( + String endpoint, Map data) async => + {'id': 'sub-1'}; + + @override + Future> patch( + String endpoint, Map data) async => + {'success': true}; +} + +void main() { + TestWidgetsFlutterBinding.ensureInitialized(); + + late List records; + late FakeApiClient api; + late DeviceService deviceService; + late SubscriberService subscriberService; + late TagService tagService; + + setUp(() { + PushFireLogger.initialize(enableLogging: true); + records = []; + Logger.root.onRecord.listen((r) => records.add(r.message)); + + api = FakeApiClient(); + deviceService = DeviceService( + api, + const PushFireConfig(apiKey: 'k', baseUrl: 'http://test/'), + ); + subscriberService = SubscriberService(api, deviceService); + tagService = TagService(api, subscriberService); + }); + + test('loginSubscriber logs the externalId but no PII', () async { + SharedPreferences.setMockInitialValues({'pushfire_device_id': 'dev-1'}); + + await subscriberService.loginSubscriber( + externalId: 'user-42', + name: 'Ada Lovelace', + email: 'ada@example.com', + phone: '+15551234567', + metadata: {'plan': 'premium'}, + ); + await Future.delayed(Duration.zero); + + final logged = records.join('\n'); + for (final secret in [ + 'Ada Lovelace', + 'ada@example.com', + '+15551234567', + 'premium', + ]) { + expect(logged.contains(secret), isFalse, reason: 'leaked $secret'); + } + // Still traceable: the identifier a support ticket arrives with. + expect(logged.contains('user-42'), isTrue); + }); + + test('addTag logs the tag id but not its value', () async { + SharedPreferences.setMockInitialValues({ + 'pushfire_device_id': 'dev-1', + 'pushfire_subscriber_id': 'sub-1', + 'pushfire_subscriber_data': json.encode(const Subscriber( + id: 'sub-1', + deviceId: 'dev-1', + externalId: 'user-42', + ).toJson()), + }); + + await tagService.addTag('user_email', 'ada@example.com'); + await Future.delayed(Duration.zero); + + final logged = records.join('\n'); + expect(logged.contains('ada@example.com'), isFalse); + expect(logged.contains('user_email'), isTrue); + }); + + test('updateTag logs the tag id but not its value', () async { + SharedPreferences.setMockInitialValues({ + 'pushfire_device_id': 'dev-1', + 'pushfire_subscriber_id': 'sub-1', + 'pushfire_subscriber_data': json.encode(const Subscriber( + id: 'sub-1', + deviceId: 'dev-1', + externalId: 'user-42', + ).toJson()), + }); + + await tagService.updateTag('user_region', 'eu-west-1'); + await Future.delayed(Duration.zero); + + final logged = records.join('\n'); + expect(logged.contains('eu-west-1'), isFalse); + expect(logged.contains('user_region'), isTrue); + }); +} diff --git a/test/utils/logger_redaction_test.dart b/test/utils/logger_redaction_test.dart new file mode 100644 index 0000000..98797f3 --- /dev/null +++ b/test/utils/logger_redaction_test.dart @@ -0,0 +1,208 @@ +import 'package:flutter_test/flutter_test.dart'; +import 'package:logging/logging.dart'; +import 'package:pushfire_sdk/src/models/device.dart'; +import 'package:pushfire_sdk/src/utils/logger.dart'; + +/// A realistic FCM token: long, high-entropy, and a send capability on its own. +const _fcmToken = 'fMEGD8pQR0-abcdefghijklmnopqrstuvwxyz0123456789:APA91bHqXwPl' + 'ZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZZ_final_ten'; + +void main() { + group('PushFireLogger.maskToken', () { + test('keeps only the first and last ten characters', () { + expect( + PushFireLogger.maskToken(_fcmToken), + '${_fcmToken.substring(0, 10)}...' + '${_fcmToken.substring(_fcmToken.length - 10)}', + ); + }); + + test('leaves the middle out entirely', () { + final masked = PushFireLogger.maskToken(_fcmToken); + expect(masked.contains('APA91bHqXwPl'), isFalse); + expect(masked.length, lessThan(_fcmToken.length)); + }); + }); + + group('PushFireLogger.redact', () { + test('masks the FCM token in a device payload', () { + const device = Device( + id: 'dev-1', + fcmToken: _fcmToken, + os: 'ios', + osVersion: '17.0', + language: 'en', + manufacturer: 'Apple', + model: 'iPhone', + appVersion: '1.0.0', + pushNotificationEnabled: true, + ); + + final redacted = PushFireLogger.redact(device.toJson()); + + expect(redacted['fcmToken'], PushFireLogger.maskToken(_fcmToken)); + expect('$redacted'.contains(_fcmToken), isFalse); + // Everything a device log is actually read for survives. + expect(redacted['id'], 'dev-1'); + expect(redacted['os'], 'ios'); + expect(redacted['pushNotificationEnabled'], true); + }); + + test('redacts subscriber PII but keeps externalId and the shape', () { + final body = { + 'data': { + 'deviceId': 'dev-1', + 'externalId': 'user-42', + 'name': 'Ada Lovelace', + 'email': 'ada@example.com', + 'phone': '+15551234567', + 'metadata': {'plan': 'premium', 'ssn': '000-00-0000'}, + }, + }; + + final redacted = PushFireLogger.redact(body); + final data = redacted['data'] as Map; + + expect(data['name'], ''); + expect(data['email'], ''); + expect(data['phone'], ''); + // The whole metadata map goes, not just its known keys — the SDK does not + // control what an integrator puts in there. + expect(data['metadata'], ''); + + // Identifiers stay: they are what a support ticket is traced by. + expect(data['externalId'], 'user-42'); + expect(data['deviceId'], 'dev-1'); + + final rendered = '$redacted'; + for (final secret in [ + 'Ada Lovelace', + 'ada@example.com', + '+15551234567', + 'premium', + '000-00-0000', + ]) { + expect(rendered.contains(secret), isFalse, reason: 'leaked $secret'); + } + }); + + test('redacts a tag value', () { + final redacted = PushFireLogger.redact({ + 'data': { + 'tagId': 'user_email', + 'subscriberId': 'sub-1', + 'value': 'ada@example.com', + }, + }); + + final data = redacted['data'] as Map; + expect(data['value'], ''); + expect(data['tagId'], 'user_email'); + }); + + test('leaves a null value null rather than claiming it was redacted', () { + final redacted = PushFireLogger.redact({'email': null, 'os': 'ios'}); + expect(redacted['email'], isNull); + }); + + test('does not mutate the caller\'s map', () { + final body = {'fcmToken': _fcmToken}; + PushFireLogger.redact(body); + expect(body['fcmToken'], _fcmToken); + }); + + test('reaches into lists of maps', () { + final redacted = PushFireLogger.redact({ + 'subscribers': [ + {'externalId': 'a', 'email': 'a@example.com'}, + {'externalId': 'b', 'email': 'b@example.com'}, + ], + }); + + final list = redacted['subscribers'] as List; + expect((list[0] as Map)['email'], ''); + expect((list[1] as Map)['email'], ''); + expect((list[0] as Map)['externalId'], 'a'); + }); + }); + + group('PushFireLogger.redactBody', () { + test('redacts a JSON response that echoes the device row', () { + final redacted = PushFireLogger.redactBody( + '{"id":"dev-1","fcm_token":"$_fcmToken","os":"ios"}', + ); + + expect(redacted.contains(_fcmToken), isFalse); + expect(redacted.contains('dev-1'), isTrue); + }); + + test('redacts snake_case PII the server sends back', () { + final redacted = PushFireLogger.redactBody( + '{"id":"sub-1","email":"ada@example.com","name":"Ada"}', + ); + + expect(redacted.contains('ada@example.com'), isFalse); + expect(redacted.contains('sub-1'), isTrue); + }); + + test('passes through a body that is not a JSON object', () { + // An HTML gateway page carries nothing the SDK sent, and mangling it + // would cost the only clue about what the proxy returned. + const html = '502 Bad Gateway'; + expect(PushFireLogger.redactBody(html), html); + }); + }); + + group('emitted log records', () { + late List records; + + setUp(() { + PushFireLogger.initialize(enableLogging: true); + records = []; + Logger.root.onRecord.listen((r) => records.add(r.message)); + }); + + test('logDeviceInfo never writes the token', () async { + const device = Device( + fcmToken: _fcmToken, + os: 'ios', + osVersion: '17.0', + language: 'en', + manufacturer: 'Apple', + model: 'iPhone', + appVersion: '1.0.0', + pushNotificationEnabled: true, + ); + + PushFireLogger.logDeviceInfo(device.toJson()); + await Future.delayed(Duration.zero); + + expect(records, isNotEmpty); + expect(records.join('\n').contains(_fcmToken), isFalse); + }); + + test('logApiRequest never writes PII from the body', () async { + PushFireLogger.logApiRequest('POST', 'http://test/login-subscriber', { + 'data': { + 'externalId': 'user-42', + 'email': 'ada@example.com', + 'phone': '+15551234567', + }, + }); + await Future.delayed(Duration.zero); + + final logged = records.join('\n'); + expect(logged.contains('ada@example.com'), isFalse); + expect(logged.contains('+15551234567'), isFalse); + expect(logged.contains('login-subscriber'), isTrue); + }); + + test('logApiResponse never writes a token echoed by the server', () async { + PushFireLogger.logApiResponse('POST', 'http://test/register-device', 200, + '{"id":"dev-1","fcmToken":"$_fcmToken"}'); + await Future.delayed(Duration.zero); + + expect(records.join('\n').contains(_fcmToken), isFalse); + }); + }); +}