From 4f1ee98489885a73c0c999448369707ee9c517cb Mon Sep 17 00:00:00 2001 From: Michael Kirk Date: Wed, 12 Jul 2017 09:51:10 -0400 Subject: [PATCH 1/2] scrub any data that slips through to logs Similar to phone number scrubbing, we leave a short prefix of the data to help with debugging without leaking much data. // FREEBIE --- Signal/src/util/OWSScrubbingLogFormatter.m | 25 ++++++++++++++----- .../test/util/OWSScrubbingLogFormatterTest.m | 23 +++++++++++++++++ 2 files changed, 42 insertions(+), 6 deletions(-) diff --git a/Signal/src/util/OWSScrubbingLogFormatter.m b/Signal/src/util/OWSScrubbingLogFormatter.m index 3a66f2ccb..79c2af478 100644 --- a/Signal/src/util/OWSScrubbingLogFormatter.m +++ b/Signal/src/util/OWSScrubbingLogFormatter.m @@ -10,17 +10,30 @@ NS_ASSUME_NONNULL_BEGIN - (NSString *)formatLogMessage:(DDLogMessage *)logMessage { - NSString *string = [super formatLogMessage:logMessage]; + NSString *logString = [super formatLogMessage:logMessage]; NSRegularExpression *phoneRegex = [NSRegularExpression regularExpressionWithPattern:@"\\+\\d{7,12}(\\d{3})" options:NSRegularExpressionCaseInsensitive error:nil]; - NSString *filteredString = [phoneRegex stringByReplacingMatchesInString:string - options:0 - range:NSMakeRange(0, [string length]) - withTemplate:@"[ REDACTED_PHONE_NUMBER:xxx$1 ]"]; - return filteredString; + logString = [phoneRegex stringByReplacingMatchesInString:logString + options:0 + range:NSMakeRange(0, [logString length]) + withTemplate:@"[ REDACTED_PHONE_NUMBER:xxx$1 ]"]; + + + // We capture only the first two characters of the hex string for logging. + NSRegularExpression *dataRegex = + [NSRegularExpression regularExpressionWithPattern:@"<([\\da-f]{2})[\\da-f]{6}( [\\da-f]{8})*>" + options:NSRegularExpressionCaseInsensitive + error:nil]; + + logString = [dataRegex stringByReplacingMatchesInString:logString + options:0 + range:NSMakeRange(0, [logString length]) + withTemplate:@"[ REDACTED_DATA:$1... ]"]; + + return logString; } @end diff --git a/Signal/test/util/OWSScrubbingLogFormatterTest.m b/Signal/test/util/OWSScrubbingLogFormatterTest.m index db9edb92e..6c46f3dd6 100644 --- a/Signal/test/util/OWSScrubbingLogFormatterTest.m +++ b/Signal/test/util/OWSScrubbingLogFormatterTest.m @@ -27,6 +27,29 @@ NS_ASSUME_NONNULL_BEGIN timestamp:[NSDate new]]; } +- (void)testDataScrubbed +{ + NSArray *dataStrings = @[ + @"<01234567 89a23def 23234567 89ab1234>", + @"<01234567 89a23def 23234567 89ab1223> ", + @"<01234567 89a23def 23234567 89ab1223> bar <01234567 89abcdef 22234567 89ab1234>" + ]; + + for (NSString *dataString in dataStrings) { + OWSScrubbingLogFormatter *formatter = [OWSScrubbingLogFormatter new]; + NSString *messageText = [NSString stringWithFormat:@"My data is %@", dataString]; + NSString *actual = [formatter formatLogMessage:[self messageWithString:messageText]]; + NSRange redactedRange = [actual rangeOfString:@"[ REDACTED_DATA:01... ]"]; + XCTAssertNotEqual( + NSNotFound, redactedRange.location, "Failed to redact data string: %@ actual: %@", dataString, actual); + + // ensure no more than the redacted portion of the data id is left in the log string + NSRange dataRange = [actual rangeOfString:@"23"]; + XCTAssertEqual( + NSNotFound, dataRange.location, "Failed to redact data string: %@, actual %@", dataString, actual); + } +} + - (void)testPhoneNumbersScrubbed { NSArray *phoneStrings = @[ From 2067697ed4f7ec1c3da1bda084ad879e60dc875d Mon Sep 17 00:00:00 2001 From: Michael Kirk Date: Wed, 12 Jul 2017 15:09:08 -0400 Subject: [PATCH 2/2] Add comment and clearer tests per CR // FREEBIE --- Signal/src/util/OWSScrubbingLogFormatter.m | 2 + .../test/util/OWSScrubbingLogFormatterTest.m | 37 +++++++++++-------- 2 files changed, 23 insertions(+), 16 deletions(-) diff --git a/Signal/src/util/OWSScrubbingLogFormatter.m b/Signal/src/util/OWSScrubbingLogFormatter.m index 79c2af478..8c563e2e5 100644 --- a/Signal/src/util/OWSScrubbingLogFormatter.m +++ b/Signal/src/util/OWSScrubbingLogFormatter.m @@ -23,6 +23,8 @@ NS_ASSUME_NONNULL_BEGIN // We capture only the first two characters of the hex string for logging. + // example log line: "Called someFunction with nsData: <01234567 89abcdef>" + // scrubbed output: "Called someFunction with nsData: [ REDACTED_DATA:01 ]" NSRegularExpression *dataRegex = [NSRegularExpression regularExpressionWithPattern:@"<([\\da-f]{2})[\\da-f]{6}( [\\da-f]{8})*>" options:NSRegularExpressionCaseInsensitive diff --git a/Signal/test/util/OWSScrubbingLogFormatterTest.m b/Signal/test/util/OWSScrubbingLogFormatterTest.m index 6c46f3dd6..0921a2b6b 100644 --- a/Signal/test/util/OWSScrubbingLogFormatterTest.m +++ b/Signal/test/util/OWSScrubbingLogFormatterTest.m @@ -29,24 +29,29 @@ NS_ASSUME_NONNULL_BEGIN - (void)testDataScrubbed { - NSArray *dataStrings = @[ - @"<01234567 89a23def 23234567 89ab1234>", - @"<01234567 89a23def 23234567 89ab1223> ", - @"<01234567 89a23def 23234567 89ab1223> bar <01234567 89abcdef 22234567 89ab1234>" - ]; + NSDictionary *expectedOutputs = @{ + @"<01234567 89a23def 23234567 89ab1234>" : @"[ REDACTED_DATA:01... ]", + @"My data is: <01234567 89a23def 23234567 89ab1223>" : @"My data is: [ REDACTED_DATA:01... ]", + @"My data is <12345670 89a23def 23234567 89ab1223> their data is <87654321 89ab1234>" : + @"My data is [ REDACTED_DATA:12... ] their data is [ REDACTED_DATA:87... ]" + }; - for (NSString *dataString in dataStrings) { - OWSScrubbingLogFormatter *formatter = [OWSScrubbingLogFormatter new]; - NSString *messageText = [NSString stringWithFormat:@"My data is %@", dataString]; - NSString *actual = [formatter formatLogMessage:[self messageWithString:messageText]]; - NSRange redactedRange = [actual rangeOfString:@"[ REDACTED_DATA:01... ]"]; - XCTAssertNotEqual( - NSNotFound, redactedRange.location, "Failed to redact data string: %@ actual: %@", dataString, actual); + OWSScrubbingLogFormatter *formatter = [OWSScrubbingLogFormatter new]; - // ensure no more than the redacted portion of the data id is left in the log string - NSRange dataRange = [actual rangeOfString:@"23"]; - XCTAssertEqual( - NSNotFound, dataRange.location, "Failed to redact data string: %@, actual %@", dataString, actual); + // Other formatters add a dynamic date prefix to log lines. We truncate that when comparing our expected output. + NSUInteger datePrefixLength = [formatter formatLogMessage:[self messageWithString:@""]].length; + + for (NSString *input in expectedOutputs) { + + NSString *rawActual = [formatter formatLogMessage:[self messageWithString:input]]; + + // strip out dynamic date portion of log line + NSString *actual = + [rawActual substringWithRange:NSMakeRange(datePrefixLength, rawActual.length - datePrefixLength)]; + + NSString *expected = expectedOutputs[input]; + + XCTAssertEqualObjects(expected, actual); } }