Skip to content

Commit

Permalink
- OCHTTP: add JSON request/response logging in line with desktop and …
Browse files Browse the repository at this point in the history 
…Android client (owncloud/client#11224) as an option and make it the default
  • Loading branch information
@felix-schwarz
felix-schwarz committed Jan 17, 2024
1 parent bc176da commit d9e7c10
Show file tree
Hide file tree
Showing 4 changed files with 225 additions and 22 deletions.
6 changes: 6 additions & 0 deletions ownCloudSDK/HTTP/Pipeline/OCHTTPPipeline.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,8 @@ typedef NS_ENUM(NSInteger, OCHTTPPipelineState)
OCHTTPPipelineStateStopping
};

typedef NSString* OCHTTPPipelineLogFormat NS_TYPED_ENUM;

NS_ASSUME_NONNULL_BEGIN

@protocol OCHTTPPipelinePolicyHandler <NSObject>
Expand Down Expand Up @@ -165,5 +167,9 @@ NS_ASSUME_NONNULL_BEGIN

extern OCClassSettingsIdentifier OCClassSettingsIdentifierHTTP;
extern OCClassSettingsKey OCHTTPPipelineSettingUserAgent;
extern OCClassSettingsKey OCHTTPPipelineSettingTrafficLogFormat;

extern OCHTTPPipelineLogFormat OCHTTPPipelineLogFormatPlainText;
extern OCHTTPPipelineLogFormat OCHTTPPipelineLogFormatJSON;

NS_ASSUME_NONNULL_END
178 changes: 165 additions & 13 deletions ownCloudSDK/HTTP/Pipeline/OCHTTPPipeline.m
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1175,13 +1175,78 @@ - (void)_scheduleTask:(OCHTTPPipelineTask *)task
// Log request
if (OCLogToggleEnabled(OCLogOptionLogRequestsAndResponses) && OCLoggingEnabled())
{
BOOL prefixedLogging = [[OCLogger classSettingForOCClassSettingsKey:OCClassSettingsKeyLogSingleLined] boolValue];
NSString *infoPrefix = (prefixedLogging ? @"[info] " : @"");
NSString *errorDescription = (error != nil) ? (prefixedLogging ? [[error description] stringByReplacingOccurrencesOfString:[NSString stringWithFormat:@"\n"] withString:[NSString stringWithFormat:@"\n[info] "]] : [error description]) : @"-";

NSArray <OCLogTagName> *extraTags = [NSArray arrayWithObjects: @"HTTP", @"Request", request.method, OCLogTagTypedID(@"RequestID", request.identifier), OCLogTagTypedID(@"URLSessionTaskID", task.urlSessionTaskID), nil];
OCTLogDebug([extraTags arrayByAddingObject:@"HTSum"], @"-> %@ %@", request.method, request.effectiveURL);
OCPFMLogDebug(OCLogOptionLogRequestsAndResponses, extraTags, @"Sending request:\n%@# REQUEST ---------------------------------------------------------\n%@URL: %@\n%@Error: %@\n%@Req Signals: %@\n%@- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -\n%@-----------------------------------------------------------------", infoPrefix, infoPrefix, request.effectiveURL, infoPrefix, errorDescription, infoPrefix, [request.requiredSignals.allObjects componentsJoinedByString:@", "], infoPrefix, [request requestDescriptionPrefixed:prefixedLogging]);
OCHTTPPipelineLogFormat httpLogFormat = [self classSettingForOCClassSettingsKey:OCHTTPPipelineSettingTrafficLogFormat];

if ([httpLogFormat isEqual:OCHTTPPipelineLogFormatJSON])
{
// OCHTTPPipelineLogFormatJSON: JSON logging
NSMutableDictionary<NSString *, id> *infoDict = [NSMutableDictionary new];
NSMutableDictionary<NSString *, NSString *> *headerDict = [NSMutableDictionary new];
NSMutableDictionary<NSString *, id> *bodyDict = [NSMutableDictionary new];

// ## Info
// IDs
infoDict[@"id"] = request.identifier;
if (![request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID] isEqual:request.identifier])
{
infoDict[@"original-id"] = request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID];
}
infoDict[@"url-session-task-id"] = task.urlSessionTaskID;
infoDict[@"required-signals"] = (request.requiredSignals.count > 0) ? request.requiredSignals.allObjects : nil;

// Method + URL
infoDict[@"method"] = request.method;
infoDict[@"url"] = request.effectiveURL.absoluteString;

// HTTP Error
if (error != nil)
{
infoDict[@"error"] = error.description;
}

// ## Header
[OCHTTPRequest formatHeaders:request.headerFields withConsumer:^(NSString *headerField, NSString *value) {
headerDict[headerField] = value;
}];

// ## Body
NSNumber *bodyLength = nil;
NSString *readableContent = [OCHTTPRequest bodyDescriptionForURL:request.bodyURL data:request.bodyData headers:request.headerFields prefixed:NO bodyLength:&bodyLength altTextDescription:NULL];
bodyDict[@"length"] = bodyLength;
bodyDict[@"data"] = readableContent;
bodyDict[@"local-data-url"] = request.bodyURL.absoluteString;

// Compose JSON dict
NSDictionary<NSString *, NSDictionary *> *jsonDict = @{
@"request" : @{
@"info" : infoDict,
@"header" : headerDict,
@"body" : bodyDict
}
};

// Log JSON dict
NSError *jsonError = nil;
NSData *jsonData;
NSString *jsonString = nil;

if ((jsonData = [NSJSONSerialization dataWithJSONObject:jsonDict options:0 error:&jsonError]) != nil)
{
jsonString = [[NSString alloc] initWithData:jsonData encoding:NSUTF8StringEncoding];
}
OCPFMLogDebug(OCLogOptionLogRequestsAndResponses, extraTags, @"REQUEST %@ %@", request.identifier, (jsonString != nil) ? jsonString : [NSString stringWithFormat:@"JSON log encoding error: %@", jsonError]);
}
else
{
// OCHTTPPipelineLogFormatPlainText + default: plain text logging
BOOL prefixedLogging = [[OCLogger classSettingForOCClassSettingsKey:OCClassSettingsKeyLogSingleLined] boolValue];
NSString *infoPrefix = (prefixedLogging ? @"[info] " : @"");
NSString *errorDescription = (error != nil) ? (prefixedLogging ? [[error description] stringByReplacingOccurrencesOfString:[NSString stringWithFormat:@"\n"] withString:[NSString stringWithFormat:@"\n[info] "]] : [error description]) : @"-";

OCTLogDebug([extraTags arrayByAddingObject:@"HTSum"], @"-> %@ %@", request.method, request.effectiveURL);
OCPFMLogDebug(OCLogOptionLogRequestsAndResponses, extraTags, @"Sending request:\n%@# REQUEST ---------------------------------------------------------\n%@URL: %@\n%@Error: %@\n%@Req Signals: %@\n%@- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -\n%@-----------------------------------------------------------------", infoPrefix, infoPrefix, request.effectiveURL, infoPrefix, errorDescription, infoPrefix, [request.requiredSignals.allObjects componentsJoinedByString:@", "], infoPrefix, [request requestDescriptionPrefixed:prefixedLogging]);
}
}

// Update task
Expand Down Expand Up @@ -1298,14 +1363,85 @@ - (void)_finishedTask:(OCHTTPPipelineTask *)task withResponse:(OCHTTPResponse *)
// Log response
if (OCLogToggleEnabled(OCLogOptionLogRequestsAndResponses) && OCLoggingEnabled())
{
BOOL prefixedLogging = [[OCLogger classSettingForOCClassSettingsKey:OCClassSettingsKeyLogSingleLined] boolValue];
NSString *infoPrefix = (prefixedLogging ? @"[info] " : @"");
NSString *errorDescription = (task.response.httpError != nil) ? (prefixedLogging ? [[task.response.httpError description] stringByReplacingOccurrencesOfString:[NSString stringWithFormat:@"\n"] withString:[NSString stringWithFormat:@"\n[info] "]] : [task.response.httpError description]) : @"-";

NSArray <OCLogTagName> *extraTags = [NSArray arrayWithObjects: @"HTTP", @"Response", task.request.method, OCLogTagTypedID(@"RequestID", task.request.identifier), OCLogTagTypedID(@"URLSessionTaskID", task.urlSessionTaskID), nil];
OCTLogDebug([extraTags arrayByAddingObject:@"HTSum"], @"<- %lu %@ (%@ %@)%@", (unsigned long)task.response.status.code, task.response.status.name, task.request.method, task.request.effectiveURL, ((task.response.redirectURL != nil) ? [NSString stringWithFormat:@" -> %@ ",task.response.redirectURL] : @""));
OCPFMLogDebug(OCLogOptionLogRequestsAndResponses, extraTags, @"Received response:\n%@# RESPONSE --------------------------------------------------------\n%@Method: %@\n%@URL: %@\n%@Request-ID: %@%@\n%@Error: %@\n%@Req Signals: %@\n%@Metrics: %@\n%@- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -\n%@-----------------------------------------------------------------", infoPrefix, infoPrefix, task.request.method, infoPrefix, task.request.effectiveURL, infoPrefix, task.request.identifier, ((task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID] != nil) ? (![task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID] isEqual:task.request.identifier] ? [NSString stringWithFormat:@" (original: %@)", task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID]] : @"") : @""), infoPrefix, errorDescription, infoPrefix, [task.request.requiredSignals.allObjects componentsJoinedByString:@", "], infoPrefix, task.metrics.compactSummary, infoPrefix, [task.response responseDescriptionPrefixed:prefixedLogging]);
OCHTTPPipelineLogFormat httpLogFormat = [self classSettingForOCClassSettingsKey:OCHTTPPipelineSettingTrafficLogFormat];

if ([httpLogFormat isEqual:OCHTTPPipelineLogFormatJSON])
{
// OCHTTPPipelineLogFormatJSON: JSON logging
NSMutableDictionary<NSString *, id> *infoDict = [NSMutableDictionary new];
NSMutableDictionary<NSString *, id> *replyDict = [NSMutableDictionary new];
NSMutableDictionary<NSString *, NSString *> *headerDict = [NSMutableDictionary new];
NSMutableDictionary<NSString *, id> *bodyDict = [NSMutableDictionary new];

// ## Info
// IDs
infoDict[@"id"] = task.request.identifier;
if (![task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID] isEqual:task.request.identifier])
{
infoDict[@"original-id"] = task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID];
}
infoDict[@"url-session-task-id"] = task.urlSessionTaskID;
infoDict[@"required-signals"] = (task.request.requiredSignals.count > 0) ? task.request.requiredSignals.allObjects : nil;

// Method + URL
infoDict[@"method"] = task.request.method;
infoDict[@"url"] = task.request.effectiveURL.absoluteString;

// Reply status + HTTP Error
replyDict[@"status"] = @(task.response.status.code);
replyDict[@"status-name"] = task.response.status.name;
replyDict[@"metrics"] = task.metrics.compactSummary;

if (task.response.httpError != nil)
{
replyDict[@"error"] = [task.response.httpError description];
}

infoDict[@"reply"] = replyDict;

// ## Header
[OCHTTPRequest formatHeaders:task.response.headerFields withConsumer:^(NSString *headerField, NSString *value) {
headerDict[headerField] = value;
}];

// ## Body
NSNumber *bodyLength = nil;
NSString *readableContent = [OCHTTPRequest bodyDescriptionForURL:task.response.bodyURL data:task.response.bodyData headers:task.response.headerFields prefixed:NO bodyLength:&bodyLength altTextDescription:NULL];
bodyDict[@"length"] = bodyLength;
bodyDict[@"data"] = readableContent;
bodyDict[@"local-data-url"] = task.response.bodyURL.absoluteString;

// Compose JSON dict
NSDictionary<NSString *, NSDictionary *> *jsonDict = @{
@"response" : @{
@"info" : infoDict,
@"header" : headerDict,
@"body" : bodyDict
}
};

// Log JSON dict
NSError *jsonError = nil;
NSData *jsonData;
NSString *jsonString = nil;

if ((jsonData = [NSJSONSerialization dataWithJSONObject:jsonDict options:0 error:&jsonError]) != nil)
{
jsonString = [[NSString alloc] initWithData:jsonData encoding:NSUTF8StringEncoding];
}
OCPFMLogDebug(OCLogOptionLogRequestsAndResponses, extraTags, @"RESPONSE %@ %@", task.request.identifier, (jsonString != nil) ? jsonString : [NSString stringWithFormat:@"JSON log encoding error: %@", jsonError]);
}
else
{
// OCHTTPPipelineLogFormatPlainText + default: plain text logging
BOOL prefixedLogging = [[OCLogger classSettingForOCClassSettingsKey:OCClassSettingsKeyLogSingleLined] boolValue];
NSString *infoPrefix = (prefixedLogging ? @"[info] " : @"");
NSString *errorDescription = (task.response.httpError != nil) ? (prefixedLogging ? [[task.response.httpError description] stringByReplacingOccurrencesOfString:[NSString stringWithFormat:@"\n"] withString:[NSString stringWithFormat:@"\n[info] "]] : [task.response.httpError description]) : @"-";

OCTLogDebug([extraTags arrayByAddingObject:@"HTSum"], @"<- %lu %@ (%@ %@)%@", (unsigned long)task.response.status.code, task.response.status.name, task.request.method, task.request.effectiveURL, ((task.response.redirectURL != nil) ? [NSString stringWithFormat:@" -> %@ ",task.response.redirectURL] : @""));
OCPFMLogDebug(OCLogOptionLogRequestsAndResponses, extraTags, @"Received response:\n%@# RESPONSE --------------------------------------------------------\n%@Method: %@\n%@URL: %@\n%@Request-ID: %@%@\n%@Error: %@\n%@Req Signals: %@\n%@Metrics: %@\n%@- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -\n%@-----------------------------------------------------------------", infoPrefix, infoPrefix, task.request.method, infoPrefix, task.request.effectiveURL, infoPrefix, task.request.identifier, ((task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID] != nil) ? (![task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID] isEqual:task.request.identifier] ? [NSString stringWithFormat:@" (original: %@)", task.request.headerFields[OCHTTPHeaderFieldNameOriginalRequestID]] : @"") : @""), infoPrefix, errorDescription, infoPrefix, [task.request.requiredSignals.allObjects componentsJoinedByString:@", "], infoPrefix, task.metrics.compactSummary, infoPrefix, [task.response responseDescriptionPrefixed:prefixedLogging]);
}
}

// Attempt delivery
Expand Down Expand Up @@ -2555,7 +2691,8 @@ + (OCClassSettingsIdentifier)classSettingsIdentifier
+ (NSDictionary<NSString *,id> *)defaultSettingsForIdentifier:(OCClassSettingsIdentifier)identifier
{
return (@{
OCHTTPPipelineSettingUserAgent : @"ownCloudApp/{{app.version}} ({{app.part}}/{{app.build}}; {{os.name}}/{{os.version}}; {{device.model}})"
OCHTTPPipelineSettingUserAgent : @"ownCloudApp/{{app.version}} ({{app.part}}/{{app.build}}; {{os.name}}/{{os.version}}; {{device.model}})",
OCHTTPPipelineSettingTrafficLogFormat : OCHTTPPipelineLogFormatJSON
});
}

Expand All @@ -2569,6 +2706,17 @@ + (OCClassSettingsMetadataCollection)classSettingsMetadata
OCClassSettingsMetadataKeyStatus : OCClassSettingsKeyStatusSupported,
OCClassSettingsMetadataKeyCategory : @"Connection",
},

OCHTTPPipelineSettingTrafficLogFormat : @{
OCClassSettingsMetadataKeyType : OCClassSettingsMetadataTypeString,
OCClassSettingsMetadataKeyDescription : @"If request and response logging is enabled, the format to use.",
OCClassSettingsMetadataKeyStatus : OCClassSettingsKeyStatusSupported,
OCClassSettingsMetadataKeyCategory : @"Connection",
OCClassSettingsMetadataKeyPossibleValues : @{
OCHTTPPipelineLogFormatPlainText : @"Plain text",
OCHTTPPipelineLogFormatJSON : @"JSON"
}
}
});
}

Expand Down Expand Up @@ -2643,3 +2791,7 @@ - (void)queueBlock:(dispatch_block_t)block withBusy:(BOOL)withBusy

OCClassSettingsIdentifier OCClassSettingsIdentifierHTTP = @"http";
OCClassSettingsKey OCHTTPPipelineSettingUserAgent = @"user-agent";
OCClassSettingsKey OCHTTPPipelineSettingTrafficLogFormat = @"traffic-log-format";

OCHTTPPipelineLogFormat OCHTTPPipelineLogFormatPlainText = @"plain";
OCHTTPPipelineLogFormat OCHTTPPipelineLogFormatJSON = @"json";
2 changes: 2 additions & 0 deletions ownCloudSDK/HTTP/Request/OCHTTPRequest.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -158,7 +158,9 @@ typedef NSDictionary<OCHTTPRequestResumeInfoKey,id>* OCHTTPRequestResumeInfo;
@property(strong) OCHTTPResponse *httpResponse;

#pragma mark - Description
+ (NSString *)bodyDescriptionForURL:(NSURL *)url data:(NSData *)data headers:(NSDictionary<NSString *, NSString *> *)headers prefixed:(BOOL)prefixed bodyLength:(NSNumber **)outBodyLengthNumber altTextDescription:(NSString **)outAltTextDescription;
+ (NSString *)bodyDescriptionForURL:(NSURL *)url data:(NSData *)data headers:(NSDictionary<NSString *, NSString *> *)headers prefixed:(BOOL)prefixed;
+ (void)formatHeaders:(NSDictionary<NSString *, NSString *> *)headers withConsumer:(void(^)(NSString *, NSString *))headerConsumer;
+ (NSString *)formattedHeaders:(NSDictionary<NSString *, NSString *> *)headers withLinePrefix:(NSString *)linePrefix;

- (NSString *)requestDescriptionPrefixed:(BOOL)prefixed;
Expand Down
61 changes: 52 additions & 9 deletions ownCloudSDK/HTTP/Request/OCHTTPRequest.m
View file
Original file line number Diff line number Diff line change
Expand Up @@ -381,7 +381,7 @@ - (void)cancel
}

#pragma mark - Description
+ (NSString *)bodyDescriptionForURL:(NSURL *)url data:(NSData *)data headers:(NSDictionary<NSString *, NSString *> *)headers prefixed:(BOOL)prefixed
+ (NSString *)bodyDescriptionForURL:(NSURL *)url data:(NSData *)data headers:(NSDictionary<NSString *, NSString *> *)headers prefixed:(BOOL)prefixed bodyLength:(NSNumber **)outBodyLengthNumber altTextDescription:(NSString **)outAltTextDescription
{
NSString *contentType = [[headers[OCHTTPHeaderFieldNameContentType] componentsSeparatedByString:@"; "] firstObject];
BOOL readableContent = [contentType hasPrefix:@"text/"] ||
Expand All @@ -403,38 +403,71 @@ + (NSString *)bodyDescriptionForURL:(NSURL *)url data:(NSData *)data headers:(NS

if (url != nil)
{
NSNumber *fileSize = nil;

if ([url getResourceValue:&fileSize forKey:NSURLFileSizeKey error:NULL])
{
if (outBodyLengthNumber != NULL)
{
*outBodyLengthNumber = fileSize;
}
}

if (readableContent)
{
return (FormatReadableData([NSData dataWithContentsOfURL:url]));
}

NSNumber *fileSize = nil;

if ([url getResourceValue:&fileSize forKey:NSURLFileSizeKey error:NULL])
if (url != nil)
{
return ([NSString stringWithFormat:@"%@[Contents from %@ (%ld bytes)]", (prefixed ? @"[body] " : @""), url.path, fileSize.integerValue]);
if (outAltTextDescription != NULL)
{
*outAltTextDescription = [NSString stringWithFormat:@"%@[Contents from %@ (%ld bytes)]", (prefixed ? @"[body] " : @""), url.path, fileSize.integerValue];
}
return (nil);
}

return ([NSString stringWithFormat:@"%@[Contents from %@]", (prefixed ? @"[body] " : @""), url.path]);
if (outAltTextDescription != NULL)
{
*outAltTextDescription = [NSString stringWithFormat:@"%@[Contents from %@]", (prefixed ? @"[body] " : @""), url.path];
}
return (nil);
}

if (data != nil)
{
if (outBodyLengthNumber != NULL)
{
*outBodyLengthNumber = @(data.length);
}

if (readableContent)
{
return (FormatReadableData(data));
}

return ([NSString stringWithFormat:@"%@[%lu bytes of %@ data]", (prefixed ? @"[body] " : @""), (unsigned long)data.length, contentType]);
if (outAltTextDescription != NULL)
{
*outAltTextDescription = [NSString stringWithFormat:@"%@[%lu bytes of %@ data]", (prefixed ? @"[body] " : @""), (unsigned long)data.length, contentType];
}
return (nil);
}

return (nil);
}

+ (NSString *)formattedHeaders:(NSDictionary<NSString *, NSString *> *)headers withLinePrefix:(NSString *)linePrefix
+ (NSString *)bodyDescriptionForURL:(NSURL *)url data:(NSData *)data headers:(NSDictionary<NSString *, NSString *> *)headers prefixed:(BOOL)prefixed
{
NSMutableString *formattedHeaders = [NSMutableString new];
NSString *readableContent = nil;
NSString *altTextDescription = nil;

readableContent = [self bodyDescriptionForURL:url data:data headers:headers prefixed:prefixed bodyLength:NULL altTextDescription:&altTextDescription];

return ((readableContent != nil) ? readableContent : altTextDescription);
}

+ (void)formatHeaders:(NSDictionary<NSString *, NSString *> *)headers withConsumer:(void(^)(NSString *, NSString *))headerConsumer
{
static dispatch_once_t onceToken;
static NSMutableArray<NSString *> *knownAuthorizationHeaders;

Expand Down Expand Up @@ -471,6 +504,16 @@ + (NSString *)formattedHeaders:(NSDictionary<NSString *, NSString *> *)headers w
}
}

headerConsumer(headerField, value);
}];
}

+ (NSString *)formattedHeaders:(NSDictionary<NSString *, NSString *> *)headers withLinePrefix:(NSString *)linePrefix
{
NSMutableString *formattedHeaders = [NSMutableString new];

[self formatHeaders:headers withConsumer:^(NSString *headerField, NSString *value) {

if (linePrefix != nil)
{
[formattedHeaders appendFormat:@"%@%@: %@\n", linePrefix, headerField, value];
Expand Down

0 comments on commit d9e7c10

Please sign in to comment.