CODEWITHSUNDEEP
objective-c
Matisse VerDuyn
Matisse VerDuyn

Reputation: 1138

Objective-C Threads

How in the world did I get this result:

2012-02-15 14:00:46.008 Test[3602:f803] 1: 0
2012-02-15 14:00:46.010 Test[3602:f803] 3: 1
2012-02-15 14:00:46.011 Test[3602:f803] 4: 3
2012-02-15 14:00:46.010 Test[3602:11703] 2: 2

From this code:

TestClass * test = [[TestClass alloc] init];
NSLog(@"1: %i", test.value++);
dispatch_queue_t queue = dispatch_get_global_queue(DISPATCH_QUEUE_PRIORITY_HIGH, 0ul);
dispatch_async(queue, ^{
     NSLog(@"2: %i", test.value++);
});
@synchronized(test) {
     NSLog(@"3: %i", test.value++);
}
NSLog(@"4: %i", test.value++);

My expectation would have been:

2012-02-15 14:00:46.008 Test[3602:f803] 1: 0
2012-02-15 14:00:46.010 Test[3602:f803] 3: 1
2012-02-15 14:00:46.011 Test[3602:f803] 4: 2
2012-02-15 14:00:46.010 Test[3602:11703] 2: 3

or even

2012-02-15 14:00:46.008 Test[3602:f803] 1: 0
2012-02-15 14:00:46.010 Test[3602:f803] 3: 1
2012-02-15 14:00:46.010 Test[3602:11703] 2: 2
2012-02-15 14:00:46.011 Test[3602:f803] 4: 3

since test.value was incremented in the log for step 2, yet it was not logged? wth?

Upvotes: 3

Views: 430

Answers (1)

Sergey Kalinichenko
Sergey Kalinichenko

Reputation: 727067

There is time between the moment a call to NSLog is initiated and the moment when NSLog writes a string to the log. It may get pre-empted during that time, and so another thread could potentially sneak in its log entry before this instance of NSLog wakes up.

Here is a possible sequence of events that leads to your printout:

  1. Thread A calls NSLog(@"2: %i", test.value++);, 2 goes on the stack as %i's parameter, and 3 is written to test.value
  2. Thread A gets pre-empted in the middle of preparing log's output
  3. Main thread calls NSLog(@"4: %i", test.value++);, 3 goes on the stack as %i's parameter, and 4 is written to test.value
  4. Main thread writes 4: 3 to the log without being pre-empted
  5. Thread A wakes up, takes 2 from the stack, formats its output, and writes 2: 2 to the log

Upvotes: 6

Related Questions