Permalink
Browse files

Fixing bug in DDFileLogger, and general improvements to logger proper…

…ty implementation. Fixes issue #13.
  • Loading branch information...
1 parent 29580ea commit f77e33f04ba478efd28741fb263db9cc9ada40b1 @robbiehanson robbiehanson committed Dec 23, 2011
Showing with 147 additions and 103 deletions.
  1. +1 −1 Lumberjack/DDFileLogger.h
  2. +96 −31 Lumberjack/DDFileLogger.m
  3. +36 −71 Lumberjack/DDLog.m
  4. +14 −0 Xcode/RollingTestMac/RollingTestMacAppDelegate.m
@@ -146,7 +146,7 @@
DDLogFileInfo *currentLogFileInfo;
NSFileHandle *currentLogFileHandle;
- NSTimer *rollingTimer;
+ dispatch_source_t rollingTimer;
unsigned long long maximumFileSize;
NSTimeInterval rollingFrequency;
View
@@ -43,7 +43,7 @@ - (NSString *)defaultLogsDirectory;
@interface DDFileLogger (PrivateAPI)
- (void)rollLogFileNow;
-- (void)maybeRollLogFileDueToAge:(NSTimer *)aTimer;
+- (void)maybeRollLogFileDueToAge;
- (void)maybeRollLogFileDueToSize;
@end
@@ -437,10 +437,6 @@ - (NSString *)formatLogMessage:(DDLogMessage *)logMessage
@implementation DDFileLogger
-@synthesize maximumFileSize;
-@synthesize rollingFrequency;
-@synthesize logFileManager;
-
- (id)init
{
DDLogFileManagerDefault *defaultLogFileManager = [[DDLogFileManagerDefault alloc] init];
@@ -467,31 +463,44 @@ - (void)dealloc
[currentLogFileHandle synchronizeFile];
[currentLogFileHandle closeFile];
- [rollingTimer invalidate];
+ if (rollingTimer)
+ {
+ dispatch_source_cancel(rollingTimer);
+ dispatch_release(rollingTimer);
+ rollingTimer = NULL;
+ }
}
////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
-#pragma mark Configuration
+#pragma mark Properties
////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
+@synthesize logFileManager;
+
- (unsigned long long)maximumFileSize
{
// The design of this method is taken from the DDAbstractLogger implementation.
- // For documentation please refer to the DDAbstractLogger implementation.
+ // For extensive documentation please refer to the DDAbstractLogger implementation.
// Note: The internal implementation should access the maximumFileSize variable directly,
// but if we forget to do this, then this method should at least work properly.
-
- if (dispatch_get_current_queue() == loggerQueue)
+
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
{
return maximumFileSize;
}
else
{
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
__block unsigned long long result;
- dispatch_sync([DDLog loggingQueue], ^{
- result = maximumFileSize;
+ dispatch_sync(loggingQueue, ^{
+ dispatch_sync(loggerQueue, ^{
+ result = maximumFileSize;
+ });
});
return result;
@@ -510,10 +519,20 @@ - (void)setMaximumFileSize:(unsigned long long)newMaximumFileSize
}};
- if (dispatch_get_current_queue() == loggerQueue)
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
+ {
block();
+ }
else
- dispatch_async([DDLog loggingQueue], block);
+ {
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
+ dispatch_async(loggingQueue, ^{
+ dispatch_async(loggerQueue, block);
+ });
+ }
}
- (NSTimeInterval)rollingFrequency
@@ -523,17 +542,23 @@ - (NSTimeInterval)rollingFrequency
// Note: The internal implementation should access the rollingFrequency variable directly,
// but if we forget to do this, then this method should at least work properly.
-
- if (dispatch_get_current_queue() == loggerQueue)
+
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
{
return rollingFrequency;
}
else
{
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
__block NSTimeInterval result;
- dispatch_sync([DDLog loggingQueue], ^{
- result = rollingFrequency;
+ dispatch_sync(loggingQueue, ^{
+ dispatch_sync(loggerQueue, ^{
+ result = rollingFrequency;
+ });
});
return result;
@@ -548,14 +573,24 @@ - (void)setRollingFrequency:(NSTimeInterval)newRollingFrequency
dispatch_block_t block = ^{ @autoreleasepool {
rollingFrequency = newRollingFrequency;
- [self maybeRollLogFileDueToAge:nil];
+ [self maybeRollLogFileDueToAge];
}};
- if (dispatch_get_current_queue() == loggerQueue)
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
+ {
block();
+ }
else
- dispatch_async([DDLog loggingQueue], block);
+ {
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
+ dispatch_async(loggingQueue, ^{
+ dispatch_async(loggerQueue, block);
+ });
+ }
}
////////////////////////////////////////////////////////////////////////////////////////////////////////////////////////
@@ -566,8 +601,9 @@ - (void)scheduleTimerToRollLogFileDueToAge
{
if (rollingTimer)
{
- [rollingTimer invalidate];
- rollingTimer = nil;
+ dispatch_source_cancel(rollingTimer);
+ dispatch_release(rollingTimer);
+ rollingTimer = NULL;
}
if (currentLogFileInfo == nil)
@@ -587,28 +623,57 @@ - (void)scheduleTimerToRollLogFileDueToAge
NSLogVerbose(@"DDFileLogger: logFileCreationDate: %@", logFileCreationDate);
NSLogVerbose(@"DDFileLogger: logFileRollingDate : %@", logFileRollingDate);
- rollingTimer = [NSTimer scheduledTimerWithTimeInterval:[logFileRollingDate timeIntervalSinceNow]
- target:self
- selector:@selector(maybeRollLogFileDueToAge:)
- userInfo:nil
- repeats:NO];
+ rollingTimer = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, 0, loggerQueue);
+
+ dispatch_source_set_event_handler(rollingTimer, ^{ @autoreleasepool {
+
+ [self maybeRollLogFileDueToAge];
+
+ }});
+
+ uint64_t delay = [logFileRollingDate timeIntervalSinceNow] * NSEC_PER_SEC;
+ dispatch_time_t fireTime = dispatch_time(DISPATCH_TIME_NOW, delay);
+
+ dispatch_source_set_timer(rollingTimer, fireTime, DISPATCH_TIME_FOREVER, 1.0);
+ dispatch_resume(rollingTimer);
}
- (void)rollLogFile
{
// This method is public.
// We need to execute the rolling on our logging thread/queue.
+ //
+ // The design of this method is taken from the DDAbstractLogger implementation.
+ // For documentation please refer to the DDAbstractLogger implementation.
- dispatch_async([DDLog loggingQueue], ^{ @autoreleasepool {
+ dispatch_block_t block = ^{ @autoreleasepool {
[self rollLogFileNow];
- }});
+ }};
+
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
+ {
+ block();
+ }
+ else
+ {
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
+ dispatch_async(loggingQueue, ^{
+ dispatch_async(loggerQueue, block);
+ });
+ }
}
- (void)rollLogFileNow
{
NSLogVerbose(@"DDFileLogger: rollLogFileNow");
+
+ if (currentLogFileHandle == nil) return;
+
[currentLogFileHandle synchronizeFile];
[currentLogFileHandle closeFile];
currentLogFileHandle = nil;
@@ -623,7 +688,7 @@ - (void)rollLogFileNow
currentLogFileInfo = nil;
}
-- (void)maybeRollLogFileDueToAge:(NSTimer *)aTimer
+- (void)maybeRollLogFileDueToAge
{
if (currentLogFileInfo.age >= rollingFrequency)
{
View
@@ -879,20 +879,20 @@ - (void)logMessage:(DDLogMessage *)logMessage
// - Must NOT require the logMessage method to acquire a lock.
// - Must NOT require the logMessage method to access an atomic property (also a lock of sorts).
//
- // Thread safety is ensured by executing access to the formatter variable on the logging thread/queue.
- // This is the same thread/queue that the logMessage method operates on.
+ // Thread safety is ensured by executing access to the formatter variable on the loggerQueue.
+ // This is the same queue that the logMessage method operates on.
//
// Note: The last time I benchmarked the performance of direct access vs atomic property access,
// direct access was over twice as fast on the desktop and over 6 times as fast on the iPhone.
-
-
+ //
+ //
// loggerQueue : Our own private internal queue that the logMessage method runs on.
// Operations are added to this queue from the global loggingQueue.
//
// loggingQueue : The queue that all log messages go through before they arrive in our loggerQueue.
//
// It is important to note that, while the loggerQueue is used to create thread-safety for our formatter,
- // changes to the formatter variable are queued on the loggingQueue.
+ // changes to the formatter variable are queued through the loggingQueue.
//
// Since this will obviously confuse the hell out of me later, here is a better description.
// Imagine the following code:
@@ -918,87 +918,52 @@ - (void)logMessage:(DDLogMessage *)logMessage
// So direct access to the formatter is only available if requested from the loggerQueue.
// In all other circumstances we need to go through the loggingQueue to get the proper value.
- if (dispatch_get_current_queue() == loggerQueue)
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
{
return formatter;
}
-
- __block id <DDLogFormatter> result;
-
- dispatch_sync([DDLog loggingQueue], ^{
- result = formatter;
- });
-
- return result;
+ else
+ {
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
+ __block id <DDLogFormatter> result;
+
+ dispatch_sync(loggingQueue, ^{
+ dispatch_sync(loggerQueue, ^{
+ result = formatter;
+ });
+ });
+
+ return result;
+ }
}
- (void)setLogFormatter:(id <DDLogFormatter>)logFormatter
{
- // This method must be thread safe and intuitive.
- // Therefore if somebody executes the following code:
- //
- // [logger setLogFormatter:myFormatter];
- // formatter = [logger logFormatter];
- //
- // They would expect formatter to equal myFormatter.
- // This functionality must be ensured by the getter and setter method.
- //
- // The thread safety must not come at a cost to the performance of the logMessage method.
- // This method is likely called sporadically, while the logMessage method is called repeatedly.
- // This means, the implementation of this method:
- // - Must NOT require the logMessage method to acquire a lock.
- // - Must NOT require the logMessage method to access an atomic property (also a lock of sorts).
- //
- // Thread safety is ensured by executing access to the formatter variable on the logging thread/queue.
- // This is the same thread/queue that the logMessage method operates on.
- //
- // Note: The last time I benchmarked the performance of direct access vs atomic property access,
- // direct access was over twice as fast on the desktop and over 6 times as fast on the iPhone.
-
-
- // loggerQueue : Our own private internal queue that the logMessage method runs on.
- // Operations are added to this queue from the global loggingQueue.
- //
- // loggingQueue : The queue that all log messages go through before they arrive in our loggerQueue.
- //
- // It is important to note that, while the loggerQueue is used to create thread-safety for our formatter,
- // changes to the formatter variable are queued on the loggingQueue.
- //
- // Since this will obviously confuse the hell out of me later, here is a better description.
- // Imagine the following code:
- //
- // DDLogVerbose(@"log msg 1");
- // DDLogVerbose(@"log msg 2");
- // [logger setFormatter:myFormatter];
- // DDLogVerbose(@"log msg 3");
- //
- // Our intuitive requirement means that the new formatter will only apply to the 3rd log message.
- // But notice what happens if we have asynchronous logging enabled for verbose mode.
- //
- // Log msg 1 starts executing asynchronously on the loggingQueue.
- // The loggingQueue executes the log statement on each logger concurrently.
- // That means it executes log msg 1 on our loggerQueue.
- // While log msg 1 is executing, log msg 2 gets added to the loggingQueue.
- // Then the user requests that we change our formatter.
- // So at this exact moment, our queues look like this:
- //
- // loggerQueue : executing log msg 1, nil
- // loggingQueue : executing log msg 1, log msg 2, nil
- //
- // So direct access to the formatter is only available if requested from the loggerQueue.
- // In all other circumstances we need to go through the loggingQueue to get the proper value.
+ // The design of this method is documented extensively in the logFormatter message (above in code).
dispatch_block_t block = ^{
- if (formatter != logFormatter)
- {
+ if (formatter != logFormatter) {
formatter = logFormatter;
}
};
- if (dispatch_get_current_queue() == loggerQueue)
+ dispatch_queue_t currentQueue = dispatch_get_current_queue();
+ if (currentQueue == loggerQueue)
+ {
block();
+ }
else
- dispatch_async([DDLog loggingQueue], block);
+ {
+ dispatch_queue_t loggingQueue = [DDLog loggingQueue];
+ NSAssert(currentQueue != loggingQueue, @"Core architecture requirement failure");
+
+ dispatch_async(loggingQueue, ^{
+ dispatch_async(loggerQueue, block);
+ });
+ }
}
- (dispatch_queue_t)loggerQueue
Oops, something went wrong.

0 comments on commit f77e33f

Please sign in to comment.