3

I'm just beginning to learn IOS development. Everytime I run this program, the console does not always display my NSLogs.

#import <Foundation/Foundation.h>

int main(int argc, const char * argv[])
{

    @autoreleasepool {

        NSMutableArray *items = [[NSMutableArray alloc] init];

        [items addObject:@"One"];
        [items addObject:@"Two"];
        [items addObject:@"Three"];

        [items insertObject:@"zero" atIndex:0];

        NSLog(@"Object at 0 is %@", [items objectAtIndex:0]);
        NSLog(@"Object at 1 is %@", [items objectAtIndex:1]);
        NSLog(@"Object at 2 is %@", [items objectAtIndex:2]);
        NSLog(@"Object at 3 is %@", [items objectAtIndex:3]);

        for (int i = 0; i < [items count]; i++) {
            NSLog(@"%@", [items objectAtIndex:i]);
        }
        items = nil;           
    }
    return 0;
}

I should be getting this in the console every time I run it:

2012-04-11 16:29:10.419 RandomPossessions[701:403] Object at 0 is zero
2012-04-11 16:29:10.421 RandomPossessions[701:403] Object at 1 is One
2012-04-11 16:29:10.422 RandomPossessions[701:403] Object at 2 is Two
2012-04-11 16:29:10.422 RandomPossessions[701:403] Object at 3 is Three
2012-04-11 16:29:10.423 RandomPossessions[701:403] zero
2012-04-11 16:29:10.423 RandomPossessions[701:403] One
2012-04-11 16:29:10.424 RandomPossessions[701:403] Two
2012-04-11 16:29:10.424 RandomPossessions[701:403] Three

But sometimes it's not all displayed. Another time I run it and I could just get:

2012-04-11 16:48:20.626 RandomPossessions[734:403] Object at 0 is zero
2012-04-11 16:48:20.628 RandomPossessions[734:403] Object at 1 is One

I have to run the program several times to get the full list of NSLogs to output to the console. Is this a bug, or am I doing something wrong? Thanks

Waynelee3d
  • 33
  • 5
  • 1
    Have you add a breakpoint? (blue things in the left of your code) – Mathieu Hausherr Apr 11 '12 at 16:38
  • Thanks. This definately helps. I put a breakpoint at the return statement. Now all my logs are output to the console. Any idea why it does not do this without the breakpoints? – Waynelee3d Apr 11 '12 at 17:11
  • Sorry I misunderstood you the first time. I thought you meant to have me put a breakpoint in. I had no breakpoints in the program at first. But when I added one, all my NSLogs got output. If the there are no breakpoints, some NSLog outputs are missing. – Waynelee3d Apr 11 '12 at 17:26
  • What happens is that the program ends before the print buffer has been emptied, so the last few lines in the buffer get lost. Placing a breakpoint at the end lets the buffer "drain" before the process is folded up. – Hot Licks Apr 11 '12 at 17:46
  • Thanks for the reply. Is there any way around this besides breakpoints? – Waynelee3d Apr 11 '12 at 18:29

2 Answers2

5

Fascinating. I just tried your code and got the same result. Here's my hypothesis:

Set a breakpoint at your line:

    [items insertObject:@"zero" atIndex:0];

When the debugger gets there, the debug panel shows one thread.

Now step forward to 

    NSLog(@"Object at 1 is %@", [items objectAtIndex:1]);

Now there are 3 threads.

I'm betting that those others 2 threads are doing the actual writing to the log. If the program finishes before those separate threads have written to the log, then they just get killed, and your logs don't get written.

I tried adding a call to

sleep(0);

at the end of the main function, and suddenly the logs started appearing appropriately.

I then tried removing that line, and the original symptoms disappeared, and I can no longer recreate the issue you were having.

Bottom line: I think this is a symptom of the program quitting before the logs have been written. If you're writing an iOS app, you won't have to worry about this kind of thing. It's just an obscure implementation detail.

Good luck learning.

Jay Wardell
  • 2,230
  • 1
  • 14
  • 13
  • I tried sleep(0); It didn't do anything for me. But the multiple thread thing where the program quits before writing the logs seems correct. I put a breakpoint just before the return statement and all my logs appear correctly every time. Thanks – Waynelee3d Apr 11 '12 at 18:28
  • I think Richard J. Ross has the right strategy with fflush(). I upvoted his answer, and I think you should try it. – Jay Wardell Apr 11 '12 at 19:01
  • Im putting flush(stdout) at the end before the return statement. My logs are still missing, though. I don't know if I'm doing it right though. – Waynelee3d Apr 11 '12 at 19:59
  • It seems that simply yielding the thread to allow the log to catch up isn't quite enough. I tried `usleep(1000)` and got a much higher success rate. When I upped it to `usleep(2000)`, I couldn't reproduce the problem after about 20 tests. – Steve Apr 22 '12 at 11:10
3

Use fflush() to write the buffer out before quitting the application:

fflush(stdout);

Or use NSFileHandle:

[[NSFileHandle fileHandleWithStandardOutput] synchronizeFile];
Richard J. Ross III
  • 55,009
  • 24
  • 135
  • 201