improve logging of http comms and of deadlocks

This commit is contained in:
Richard Frith-Macdonald 2018-03-16 15:11:02 +00:00
parent 7c1b9b4d15
commit 81102fae85
5 changed files with 109 additions and 33 deletions

View file

@ -1,3 +1,12 @@
2018-03-16 Richard Frith-Macdonald <rfm@gnu.org>
* Headers/Foundation/NSLock.h: Expose pointer to function handling
logging of deadlocks.
* Source/NSLock.m: Indirect via pointer so apps can intercept the
logging of deadlocks.
* Source/GSHTTPURLHandle.m: Provide more detailed debug logging.
* Source/NSURLProtocol.m: Provide more detailed debug logs.
2018-02-25 Richard Frith-Macdonald <rfm@gnu.org>
* Source/GSeq.h: Fixup error in last modification.

View file

@ -319,6 +319,14 @@ extern "C" {
@end
#if !NO_GNUSTEP
typedef void NSLock_error_handler (id obj, SEL _cmd, BOOL stop);
/** Code may replace this function pointer in order to intercept the normal
* logging of a deadlock.
*/
GS_EXPORT NSLock_error_handler *_NSLock_error_handler;
#endif
#if defined(__cplusplus)
}
#endif

View file

@ -127,6 +127,9 @@ static NSString *httpVersion = @"1.1";
writing,
reading,
} connectionState;
@public
NSString *in;
NSString *out;
}
- (int) setDebug: (int)flag;
- (void) _tryLoadInBackground: (NSURL*)fromURL;
@ -247,15 +250,15 @@ debugRead(GSHTTPURLHandle *handle, NSData *data)
{
char *esc = [data escapedRepresentation: 0];
NSLog(@"Read for %p of %d bytes (escaped) - '%s'\n<[%s]>",
handle, len, esc, hex);
NSLog(@"Read for %p %@ of %d bytes (escaped) - '%s'\n<[%s]>",
handle, handle->in, len, esc, hex);
free(esc);
free(hex);
return;
}
}
NSLog(@"Read for %p of %d bytes - '%*.*s'\n<[%s]>",
handle, len, len, len, ptr, hex);
NSLog(@"Read for %p %@ of %d bytes - '%*.*s'\n<[%s]>",
handle, handle->in, len, len, len, ptr, hex);
free(hex);
}
static void
@ -277,15 +280,15 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
{
char *esc = [data escapedRepresentation: 0];
NSLog(@"Write for %p of %d bytes (escaped) - '%s'\n<[%s]>",
handle, len, esc, hex);
NSLog(@"Write for %p %@ of %d bytes (escaped) - '%s'\n<[%s]>",
handle, handle->out, len, esc, hex);
free(esc);
free(hex);
return;
}
}
NSLog(@"Write for %p of %d bytes - '%*.*s'\n<[%s]>",
handle, len, len, len, ptr, hex);
NSLog(@"Write for %p %@ of %d bytes - '%*.*s'\n<[%s]>",
handle, handle->out, len, len, len, ptr, hex);
free(hex);
}
@ -338,6 +341,8 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
[sock closeFile];
DESTROY(sock);
}
DESTROY(out);
DESTROY(in);
DESTROY(u);
DESTROY(url);
DESTROY(dat);
@ -417,7 +422,11 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
IF_NO_GC([self retain];)
if (debug)
NSLog(@"%@ %p %s", NSStringFromSelector(_cmd), self, keepalive?"K":"");
{
NSLog(@"%@ %p %@ %s",
NSStringFromSelector(_cmd), self, out,
(keepalive ? "re-used connection" : "initial connection"));
}
s = [basic mutableCopy];
if ([[u query] length] > 0)
@ -883,7 +892,9 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
IF_NO_GC([self retain];)
if (debug)
NSLog(@"%@ %p %s", NSStringFromSelector(_cmd), self, keepalive?"K":"");
{
NSLog(@"%@ %p %s", NSStringFromSelector(_cmd), self, keepalive?"K":"");
}
d = [dict objectForKey: NSFileHandleNotificationDataItem];
if (YES == debug) debugRead(self, d);
@ -958,15 +969,10 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
NSString *path;
IF_NO_GC([self retain];)
if (debug)
NSLog(@"%@ %p %s", NSStringFromSelector(_cmd), self, keepalive?"K":"");
path = [[[u fullPath] stringByTrimmingSpaces]
stringByAddingPercentEscapesUsingEncoding: NSUTF8StringEncoding];
if ([path length] == 0)
{
path = @"/";
}
[nc removeObserver: self
name: GSFileHandleConnectCompletionNotification
object: sock];
/*
* See if the connection attempt caused an error.
@ -986,14 +992,29 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
return;
}
[nc removeObserver: self
name: GSFileHandleConnectCompletionNotification
object: sock];
in = [[NSString alloc] initWithFormat: @"(%@:%@ <-- %@:%@)",
[sock socketLocalAddress], [sock socketLocalService],
[sock socketAddress], [sock socketService]];
out = [[NSString alloc] initWithFormat: @"(%@:%@ --> %@:%@)",
[sock socketLocalAddress], [sock socketLocalService],
[sock socketAddress], [sock socketService]];
if (debug)
{
NSLog(@"%@ %p", NSStringFromSelector(_cmd), self);
}
/*
* Build HTTP request.
*/
path = [[[u fullPath] stringByTrimmingSpaces]
stringByAddingPercentEscapesUsingEncoding: NSUTF8StringEncoding];
if ([path length] == 0)
{
path = @"/";
}
/*
* If SSL via proxy, set up tunnel first
*/
@ -1188,6 +1209,8 @@ debugWrite(GSHTTPURLHandle *handle, NSData *data)
[nc removeObserver: self name: nil object: sock];
[sock closeFile];
DESTROY(sock);
DESTROY(in);
DESTROY(out);
connectionState = idle;
if (debug)
NSLog(@"%@ %p restart on new connection",

View file

@ -141,7 +141,7 @@
}\
if (EDEADLK == err)\
{\
_NSLockError(self, _cmd, YES);\
(*_NSLock_error_handler)(self, _cmd, YES);\
}\
}
@ -191,9 +191,11 @@ void _NSLockError(id obj, SEL _cmd, BOOL stop)
NSStringFromSelector(_cmd), obj);
NSLog(@"*** Break on _NSLockError() to debug.");
if (YES == stop)
pthread_mutex_lock(&deadlock);
pthread_mutex_lock(&deadlock);
}
NSLock_error_handler *_NSLock_error_handler = _NSLockError;
// Exceptions
NSString *NSLockException = @"NSLockException";
@ -269,7 +271,7 @@ MLOCK
}
if (EDEADLK == err)
{
_NSLockError(self, _cmd, NO);
(*_NSLock_error_handler)(self, _cmd, NO);
}
sched_yield();
} while ([limit timeIntervalSinceNow] > 0);

View file

@ -37,6 +37,7 @@
#import "GSURLPrivate.h"
#import "GNUstepBase/GSMime.h"
#import "GNUstepBase/NSData+GNUstepBase.h"
#import "GNUstepBase/NSStream+GNUstepBase.h"
#import "GNUstepBase/NSString+GNUstepBase.h"
#import "GNUstepBase/NSURL+GNUstepBase.h"
@ -68,6 +69,12 @@ zfree(void *opaque, void *mem)
#endif
#endif
@interface NSURLProtocol (Debug)
- (NSString*) in;
- (NSString*) out;
@end
static void
debugRead(id handle, int len, const unsigned char *ptr)
{
@ -92,16 +99,16 @@ debugRead(id handle, int len, const unsigned char *ptr)
freeWhenDone: NO];
esc = [data escapedRepresentation: 0];
NSLog(@"Read for %p of %d bytes (escaped) - '%s'\n<[%s]>",
handle, len, esc, hex);
NSLog(@"Read for %p %@ of %d bytes (escaped) - '%s'\n<[%s]>",
handle, [handle in], len, esc, hex);
free(esc);
RELEASE(data);
free(hex);
return;
}
}
NSLog(@"Read for %p of %d bytes - '%*.*s'\n<[%s]>",
handle, len, len, len, ptr, hex);
NSLog(@"Read for %p %@ of %d bytes - '%*.*s'\n<[%s]>",
handle, [handle in], len, len, len, ptr, hex);
free(hex);
}
static void
@ -127,16 +134,16 @@ debugWrite(id handle, int len, const unsigned char *ptr)
length: len
freeWhenDone: NO];
esc = [data escapedRepresentation: 0];
NSLog(@"Write for %p of %d bytes (escaped) - '%s'\n<[%s]>",
handle, len, esc, hex);
NSLog(@"Write for %p %@ of %d bytes (escaped) - '%s'\n<[%s]>",
handle, [handle out], len, esc, hex);
free(esc);
RELEASE(data);
free(hex);
return;
}
}
NSLog(@"Write for %p of %d bytes - '%*.*s'\n<[%s]>",
handle, len, len, len, ptr, hex);
NSLog(@"Write for %p %@ of %d bytes - '%*.*s'\n<[%s]>",
handle, [handle out], len, len, len, ptr, hex);
free(hex);
}
@ -368,6 +375,8 @@ typedef struct {
NSCachedURLResponse *cachedResponse;
id <NSURLProtocolClient> client; // Not retained
NSURLRequest *request;
NSString *in;
NSString *out;
#if USE_ZLIB
z_stream z; // context for decompress
BOOL compressing; // are we compressing?
@ -512,6 +521,8 @@ static NSURLProtocol *placeholder = nil;
[this->output close];
DESTROY(this->input);
DESTROY(this->output);
DESTROY(this->in);
DESTROY(this->out);
}
DESTROY(this->cachedResponse);
DESTROY(this->request);
@ -597,6 +608,17 @@ static NSURLProtocol *placeholder = nil;
@end
@implementation NSURLProtocol (Debug)
- (NSString*) in
{
return (this) ? (this->in) : nil;
}
- (NSString*) out
{
return (this) ? (this->out) : nil;
}
@end
@implementation NSURLProtocol (Private)
+ (Class) _classToHandleRequest:(NSURLRequest *)request
@ -1449,6 +1471,18 @@ static NSURLProtocol *placeholder = nil;
{
NSLog(@"%@ HTTP output stream opened", self);
}
this->in = [[NSString alloc]
initWithFormat: @"(%@:%@ <-- %@:%@)",
[stream propertyForKey: GSStreamLocalAddressKey],
[stream propertyForKey: GSStreamLocalPortKey],
[stream propertyForKey: GSStreamRemoteAddressKey],
[stream propertyForKey: GSStreamRemotePortKey]];
this->out = [[NSString alloc]
initWithFormat: @"(%@:%@ --> %@:%@)",
[stream propertyForKey: GSStreamLocalAddressKey],
[stream propertyForKey: GSStreamLocalPortKey],
[stream propertyForKey: GSStreamRemoteAddressKey],
[stream propertyForKey: GSStreamRemotePortKey]];
DESTROY(_writeData);
_writeOffset = 0;
if ([this->request HTTPBodyStream] == nil)