Compress-Upload-CocoaLumberjack - My First CocoaPod

5 minute read

I just published my first CocoaPod: Compress-Upload-CocoaLumberjack:

Remote logging via NSURLSession transfer to upload compressed CocoaLumberjack logs to an HTTP server.

james@Jamess-iMac: ~/Projects/Compress-Upload-CocoaLumberjack on master[?]
$ pod trunk me
  - Name:     James Stout
  - Email:    stoutyhk@gmail.com
  - Since:    May 7th, 20:14
  - Pods:
    - Compress-Upload-CocoaLumberjack
  - Sessions:
    - May 7th, 20:14 - September 14th, 21:44. IP: 203.218.233.190 Description: imac

james@Jamess-iMac: ~/Projects/Compress-Upload-CocoaLumberjack on master[?]
$ pod search Compress-Upload-CocoaLumberjack 2> /dev/null

-> Compress-Upload-CocoaLumberjack (0.1.2)
   Remote logging via NSURLSession transfer to upload compressed CocoaLumberjack logs to an HTTP server.
   pod 'Compress-Upload-CocoaLumberjack', '~> 0.1.2'
   - Homepage: https://github.com/jamesstout/Compress-Upload-CocoaLumberjack
   - Source:   https://github.com/jamesstout/Compress-Upload-CocoaLumberjack.git
   - Versions: 0.1.2, 0.1.1, 0.1.0 [Specs repo]

The rationale for creating this Pod was that the demo log file compression project in CocoaLumberjack just zips archived files, and BackgroundUpload-CocoaLumberjack only uploads uncompressed log files. I wanted to compress, and then upload, to save space and bandwidth.

So first things first, thank you to pushd and CocoaLumberjack for their work, inspiration, examples and permissive licenses. This wouldn’t exist without them.

CocoaLumberjack is a fast & simple, yet powerful & flexible logging framework

Lumberjack is Fast & Simple, yet Powerful & Flexible.

It is similar in concept to other popular logging frameworks such as log4j, yet is designed specifically for Objective-C, and takes advantage of features such as multi-threading, grand central dispatch (if available), lockless atomic operations, and the dynamic nature of the Objective-C runtime.

Lumberjack is Fast

In most cases it is an order of magnitude faster than NSLog.

Lumberjack is Powerful

One log statement can be sent to multiple loggers, meaning you can log to a file and the console simultaneously. Want more? Create your own loggers (it’s easy) and send your log statements over the network. Or to a database or distributed file system. The sky is the limit.

Check out the benchmarks.

The default philosophy for asynchronous logging is very simple:

  • Log messages with errors should be executed synchronously.
  • All other log messages, such as debug output, are executed asynchronously.

Getting started is simple. This will add a pair of “loggers” and your log statements will be sent to the Console.app and the Xcode console (just like a normal NSLog).

#define LOG_LEVEL_DEF ddLogLevel
#import <CocoaLumberjack/CocoaLumberjack.h>

[DDLog addLogger:[DDOSLogger sharedInstance]];

To add another logger, one that writes to a file:

DDFileLogger *fileLogger = [[DDFileLogger alloc] init];
fileLogger.rollingFrequency = 60 * 60 * 24; // 24 hour rolling
fileLogger.logFileManager.maximumNumberOfLogFiles = 7;

[DDLog addLogger:fileLogger];

That’s a fairly standard log file setup, with one file per day, for a week. After a week, the oldest file is deleted.

Then to log, just convert your NSLog calls:

// Convert from this:
NSLog(@"Broken sprocket detected!");
NSLog(@"User selected file:%@ withSize:%u", filePath, fileSize);

// To this:
DDLogError(@"Broken sprocket detected!");
DDLogVerbose(@"User selected file:%@ withSize:%u", filePath, fileSize);

Those logs will be set to the console, and to the log file.

If you make the logFileManager a CompressingLogFileManager, per the LogFileCompressor demo project mentioned above, your setup looks like this:

CompressingLogFileManager *logFileManager = [[CompressingLogFileManager alloc] init];
fileLogger = [[DDFileLogger alloc] initWithLogFileManager:logFileManager];

// 1kB and 1 min, just to demo quick rolling/compressing
fileLogger.maximumFileSize  = 1024 * 1;  // 1 KB
fileLogger.rollingFrequency =   60 * 1;  // 1 Minute

fileLogger.logFileManager.maximumNumberOfLogFiles = 4;

[DDLog addLogger:[DDOSLogger sharedInstance]];
[DDLog addLogger:fileLogger];

With this setup, your log file is ‘archived’ and then compressed to a .gz file. After a while, the log folder looks like this:

log-folder

Seems the .gz files are excluded from the deletion based on maximumNumberOfLogFiles, so the folder would just fill up, I think.

I deal with this in Compress-Upload-CocoaLumberjack. To set up Compress-Upload-CocoaLumberjack, you need an HTTP(S) server with an endpoint that accepts the log files, then instantiate the logger with your URL:

// change the URL to your domain/endpoint
NSMutableURLRequest *request = [NSMutableURLRequest
                                    requestWithURL:[NSURL URLWithString:@"http://localhost:3000/log"]];
[request setHTTPMethod:@"POST"];

logFileManager = [[CompressingAndUploadingLogFileManager alloc] initWithUploadRequest:request];

fileLogger = [[DDFileLogger alloc] initWithLogFileManager:logFileManager];

// set to 1 min and 1kB so they roll quickly
fileLogger.maximumFileSize  = 1024 * 100;  // 1 KB
fileLogger.rollingFrequency =   60 * 1;  // 1 Minute

fileLogger.logFileManager.maximumNumberOfLogFiles = 4;

[DDLog addLogger:[DDOSLogger sharedInstance]];
[DDLog addLogger:fileLogger];

The compression behaviour is the same as in LogFileCompressor, except in compressionDidSucceed

#pragma mark - compressionDidSucceed
- (void)compressionDidSucceed:(DDLogFileInfo *)logFile
{
    NSLogVerbose(@"CompressingAndUploadingLogFileManager: compressionDidSucceed: %@", logFile.fileName);
  
    // at this point we want to upload logFile, if the dontUpload flag isn't set
    if(doUpload == YES){
        [self uploadArchivedFile:logFile];
    }
    self.isCompressing = NO;
  
    [self compressNextLogFile];
}

uploadArchivedFile eventually calls:

- (void)uploadLogFile:(NSString *)logFilePath
{
    NSMutableURLRequest *request = [self.uploadRequest mutableCopy];
    [request setValue:[logFilePath stringByAddingPercentEncodingWithAllowedCharacters:[NSCharacterSet URLHostAllowedCharacterSet]] forHTTPHeaderField:@"X-BackgroundUpload-File"];

    // added extra header to identify upload
    [request setValue:[UIDevice.currentDevice.identifierForVendor.UUIDString stringByAddingPercentEncodingWithAllowedCharacters:[NSCharacterSet URLHostAllowedCharacterSet]] forHTTPHeaderField:@"X-BackgroundUpload-File-UUID"];
  
    NSURLSessionTask *task = [self.session uploadTaskWithRequest:request fromFile:[NSURL fileURLWithPath:logFilePath]];
    task.taskDescription = logFilePath;
    [task resume];
    if ([self.delegate respondsToSelector:@selector(attemptingUploadForFilePath:)]) {
        [self.delegate attemptingUploadForFilePath:logFilePath];
    }
}

The X-BackgroundUpload-File contains the filename. I added X-BackgroundUpload-File-UUID to anonymously identify each device so I could separate the log files on the server-side, and do a few security checks.

I’m not going to publish the server code, as I’m pretty sure it has some vulnerabilities! Something like this, in PHP:


function hhud($var, $index){
    return  isset($var[$index]) ? rawurldecode($var[$index]) : '';
}

$request_body = @file_get_contents('php://input');

if($request_body != null ){

    // do some checks and validation on input

    $fullFileName = hhud($_SERVER, "HTTP_X_BACKGROUNDUPLOAD_FILE");
    // File path to save file
    $filePath = 'xxxxx/';
    $fileName = '';
    $fileDir = 'xxxxx/';

    if($fullFileName != ''){
        $fileName = basename($fullFileName);
        $fileName = preg_replace('/\s+/', '-', $fileName);
    }

    $filePath = $filePath . $fileDir;

    $file = $filePath . "/" . $fileName;

    // Write the request body to file
    if(file_put_contents($file, $request_body) === FALSE){
        $serverDeets = var_export($_SERVER, 1);
        throw new Exception( "Failed to write to file:" . $file  . "\n\n\$_SERVER was:\n $serverDeets\n ");
    }
}
else{
    http_response_code(400);
    http_response_code();
    exit;
}

To deal with old compressed files in the logs directory, I added uploadOldCompressedLogFiles to the CompressingAndUploadingLogFileManager init:

-(void)uploadOldCompressedLogFiles{

    if(doUpload == NO){
        return;
    }

    NSArray *unsortedLogFileInfos = [self unsortedLogFileInfosGZ];

    for (DDLogFileInfo *fileInfo in unsortedLogFileInfos) {
        NSLogVerbose(@"CompressingAndUploadingLogFileManager: fileInfo: %@", fileInfo);

        if (fileInfo.isArchived) {
            NSLogVerbose(@"is Archived, uploading...");
            [self uploadArchivedFile:fileInfo];
        }
    }
}

You might have spotted that there’s a property on the LogFileManager that you can set to prevent uploads (it defaults to YES). To stop uploading, simply set to NO.

logFileManager.doUpload = NO;

In my HKWarnings app, I can set this flag from my server, enabling me to remotely switch log file uploading on and off.

On the server, I end up with folders full of gzipped log files:

Log files Log tree

I take a copy, unzip and grep the logs for insights. For example, this lists debug lines and orders them by the number of times they occur:

egrep '\[\D\]' *.log | grep -Po ' \[.*' | sed 's/^ *//g' | sort | uniq -c | sort -n
1182 [D] [Warning -[Warning isItNight]][Line 1619] in isItNight
1343 [D] [WarningViewController3 -[WarningViewController3 showLabel]][Line 2152] have not purchased ads
1361 [D] [NSMutableString+HKWUtilities -[NSMutableString(HKWUtilities) hkw_base64EncodedURLQueryString:]][Line 14] encQueryString is []
1377 [D] [WarningViewController3 -[WarningViewController3 showLabel]][Line 2136] In showLabel

So I can see I should make sure these are performant:

  • isItNight
  • hkw_base64EncodedURLQueryString

In fact I’ve already released a version where hkw_base64EncodedURLQueryString is 66% faster and isItNight is ~30% faster:

Is it night test Is it night 2 tests

Final test to check the output of the new version matches the old version:

- (void)testisItNight_isItNight2 {
    Warning *warning = [Warning alloc];
    BOOL isitNight2 = [warning isItNight2];
    BOOL isitNight = [warning isItNight];
    expect(isitNight2).to.equal(isitNight);
}

Anyway, here it is in action (click through to view the video):

Git files changes screenshot