Weak references / logging strange behaviour


#1

Hi,
while working on weak reference example, I decided to place NSLog before setting backpack to nil. To my surprise the output was completely unexplainable.

[code]int main(int argc, const char * argv[])
{
@autoreleasepool {
BNRItem *backpack = [[BNRItem alloc] init];
[backpack setItemName:@"[color=#FFFFFF][/color]Backpack"];

	BNRItem *calculator = [[BNRItem alloc] init];
	[calculator setItemName:@"Calculator"];
	
	[backpack setContainedItem:calculator];

	//NSLog(@"Container: %@", [calculator container]);
	backpack = nil;
	NSLog(@"Container: %@", [calculator container]);
	calculator = nil;
}
return 0;

[/code]

Here’s the output with no extra NSLog (exactly as in the book):

[size=85]2012-04-09 19:05:19.581 RandomPosessions[2999:403] Destroyed: {7b414350}: Backpack (): Worth $0, recorded on 2012-04-09 23:05:19 +0000
2012-04-09 19:05:19.582 RandomPosessions[2999:403] Container: (null)
2012-04-09 19:05:19.584 RandomPosessions[2999:403] Destroyed: {7b415ac0}: Calculator (): Worth $0, recorded on 2012-04-09 23:05:19 +0000
[/size]

and here’s an output with extra NSLog:

[size=85]2012-04-09 19:06:23.502 RandomPosessions[3006:403] Container: {514350}: Backpack (): Worth $0, recorded on 2012-04-09 23:06:23 +0000
2012-04-09 19:06:23.505 RandomPosessions[3006:403] Container: {514350}: Backpack (): Worth $0, recorded on 2012-04-09 23:06:23 +0000
2012-04-09 19:06:23.506 RandomPosessions[3006:403] Destroyed: {514350}: Backpack (): Worth $0, recorded on 2012-04-09 23:06:23 +0000
2012-04-09 19:06:23.508 RandomPosessions[3006:403] Destroyed: {515ac0}: Calculator (): Worth $0, recorded on 2012-04-09 23:06:23 +0000[/size]

I would like to hear any explanations. I also noticed that sometimes I get only one output line (without extra NSLog in the code) like this:
[size=85]2012-04-09 19:07:24.272 RandomPosessions[3032:403] Destroyed: {1214350}: Backpack (): Worth $0, recorded on 2012-04-09 23:07:24 +0000[/size]

The subsequent run without any changes will render the proper output:
[size=85]2012-04-09 19:07:59.002 RandomPosessions[3035:403] Destroyed: {21c14350}: Backpack (): Worth $0, recorded on 2012-04-09 23:07:58 +0000
2012-04-09 19:07:59.004 RandomPosessions[3035:403] Container: (null)
2012-04-09 19:07:59.005 RandomPosessions[3035:403] Destroyed: {21c15ab0}: Calculator (): Worth $0, recorded on 2012-04-09 23:07:58 +0000[/size]


#2

Basically, it boils down to ARC choosing when to actually release objects. There are a lot of optimizations built into ARC, and it handles some situations better than others. In this particular case, using the calculator’s container (in the NSLog function) makes the main function retain the backpack again. So that object hangs out for a bit (until the end of the autorelease pool, most likely), even though you’ve cleared your other pointer to it.

At the end of the day, ARC has done the right thing, just not as quickly as you might expect. If you are interested, you can always go to the Product menu in Xcode and select Generate Output->Assembly File to see what ARC is doing. Look in the assembly comments for words like retain and release.


#3

The program goes into an infinite loop in -(void) setContainedItem:(BNRItem *)i
and I have had to re-boot the entire system. It is looping in setContainedItem between containedItem = i;
and [i setContainedItem:self];
I added
__weak BNRItem *container; in BNRItem.h and it didn’t help at all! I will move on but
I would like like to know why __weak isn’t working!!

-(void) setContainedItem:(BNRItem *)i
{
containedItem = i;
[i setContainedItem:self];
}