What does NSLog actually do?

Question

Hi,

I am having a weird problem. I am using a method from Apple's private frameworks in my application. When I call it for the first time, it works. When I call it for the second time immediately without anything in between, it crashes. However, if I put NSLog between the two calls, it works wonderfully. So I try removing NSLog and puting for-loops, sleep(), printf("..."), and fprintf(stderr, "...") between them to emulate NSLog, but it doesn't help. I am wondering how the method knows that I use NSLog? In other words, what does NSLog actually do to affect the behaviors of the method?

Thank you very much!

EDIT:

I seem to solve this problem. I will share my solution here and hope it may be useful to some people.

I am creating a multitouch-related application using MultitouchSupport.framework. I copied code from http://aladino.dmi.unict.it/?a=multitouch and added a CFRelease at the end of the loop. So, basically, my main method looks like this :

int main(void) { 
    int i; 
    NSMutableArray* deviceList = (NSMutableArray*)MTDeviceCreateList(); //grab our device list 
    for(i = 0; i<[deviceList count]; i++) { //iterate available devices 
        MTRegisterContactFrameCallback([deviceList objectAtIndex:i], touchCallback); //assign callback for device 
        MTDeviceStart([deviceList objectAtIndex:i], 0); //start sending events 
    }
    CFRelease((CFMutableArrayRef)deviceList); 
    printf("Ctrl-C to abort\n"); 
    sleep(-1); 
    return 0; 
}

After running for a while, it will show "Program received signal: “EXC_BAD_ACCESS”." And here is the stack trace:

#0 0x7fff8795496e in ParsedMultitouchFrameRepInitialize
#1 0x7fff879565b1 in mt_HandleMultitouchFrame
#2 0x7fff87955a03 in mt_DequeueDataFromDriver
#3 0x7fff87955b29 in mt_DequeueMultitouchDataFromDriverThreadEntry
#4 0x7fff831b3456 in _pthread_start
#5 0x7fff831b3309 in thread_start

However, if I put NSLog below MTDeviceStart, it will not crash.

The reason I added CFRelease((CFMutableArrayRef)deviceList) to the original code is that I think objects that are created from functions named *Create* or *Copy* should be released by ourselves. But it turns out that if I remove it like the original code does, it will not crash, even without using NSLog.

So, maybe it's because I release deviceList too early? But if that's so, why does NSLog seem to be able to prevent the crash?

Answer 1

It could be a problem with memory management: an extraneous release perhaps. If you post the traceback, it might be some help in tracking down the issue. (As it turns out, someone on Twitter I follow mentioned something like this last night).

Answer 2

It takes a long time. I'm not sure why. It prints the date/time, process name, process ID, thread ID, and (finally) the string you asked for. I think it also sends the log message to syslogd (either Xcode or iPCU's console shows multiline NSLogs as a single entry; I forget which); the IPC there might be significant.

Try using syslog() (#import <syslog.h> and then syslog(LOG_INFO, "Hello there!");, if it works but you get no output, try changing the priority (see man 3 syslog).

Answer 3

Something similar to this:

static inline void NSLogMessageString(NSString *string){
  NSString *date=[[NSDate date]
   descriptionWithCalendarFormat:@"%Y-%m-%d %H:%M:%S.%F"
                        timeZone:nil locale:nil];
  NSString *process=[[NSProcessInfo processInfo] processName];

  NSLogFormat(@"%@ %@[%d:%lx] %@",date,process,NSPlatformProcessID(),NSPlatformThreadID(),string);
}

void NSLogv(NSString *format,va_list arguments) {
  NSString *string=NSStringNewWithFormat(format,nil,arguments,NULL);

  NSLogMessageString(string);

 [string release];
}

void NSLog(NSString *format,...) {
  va_list arguments;

  va_start(arguments,format);

  NSLogv(format,arguments);
}

Thanks for asking this question lol, I wanted to rewrite it so I could add debugging variables, meaning I could turn all NSLogging calls off when needed..