Discussion:
How to debug crash in NSOperation?
(too old to reply)
Gerriet M. Denkmann
2017-03-27 03:06:55 UTC
Permalink
macOS 12.3

This is a rather rare bug (never seen before):

Thread 12 Crashed:: Dispatch queue: เสือ :: NSOperation 0x61800184fbd0 (QOS: UTILITY)
0 libsystem_kernel.dylib 0x00007fffb3d65dd6 __pthread_kill + 10
1 libsystem_pthread.dylib 0x00007fffb3e51787 pthread_kill + 90
2 libsystem_c.dylib 0x00007fffb3ccb420 abort + 129
3 libc++abi.dylib 0x00007fffb282885a abort_message + 266
4 libc++abi.dylib 0x00007fffb284dc4f default_terminate_handler() + 267
5 libobjc.A.dylib 0x00007fffb3357b8e _objc_terminate() + 103
6 libc++abi.dylib 0x00007fffb284ad69 std::__terminate(void (*)()) + 8
7 libc++abi.dylib 0x00007fffb284ade3 std::terminate() + 51
8 libdispatch.dylib 0x00007fffb3c010cc _dispatch_client_callout + 28
9 libdispatch.dylib 0x00007fffb3c17ae5 _dispatch_queue_serial_drain + 896
10 libdispatch.dylib 0x00007fffb3c09cd9 _dispatch_queue_invoke + 1046
11 libdispatch.dylib 0x00007fffb3c02e70 _dispatch_root_queue_drain + 476
12 libdispatch.dylib 0x00007fffb3c02c47 _dispatch_worker_thread3 + 99
13 libsystem_pthread.dylib 0x00007fffb3e4e712 _pthread_wqthread + 1299
14 libsystem_pthread.dylib 0x00007fffb3e4e1ed start_wqthread + 13

The NSOperationQueue named “ เสือ" is created at the start of the app thusly:

@interface EchoStreamServer()
@property (strong) NSOperationQueue *commandOperationQueue;
@end

@implementation EchoStreamServer

- (instancetype)initWithInputStream: (NSInputStream *)istr outputStream:(NSOutputStream *)ostr owner: (id <EchoProtocol>)oo security: securityThing service: (NSNetService *)svice;
{
self = [ super initWithInputStream: istr …. ];
if ( self == nil ) return nil;

_commandOperationQueue = [ [ NSOperationQueue alloc ] init ];
_commandOperationQueue.name = @"เสือ";
_commandOperationQueue.qualityOfService = [ oo echoQualityOfService ]; // NSQualityOfServiceUtility

return self;
}

// this is called as answer to a request from a client:
- (void)sendToOwnerObject: obb seqNbr: (NSUInteger)seqNbr;
{
if ( self.owner == nil )…. // error

NSBlockOperation *echoOperation = [ [ NSBlockOperation alloc ] init ];
__weak NSBlockOperation *weakBo = echoOperation;

[ echoOperation addExecutionBlock: ^void(void)
{ [ self.owner echoObject: obb
seqNbr: seqNbr
from: self
operation: weakBo
];
}
];

[ self.commandOperationQueue addOperation: echoOperation ];
}

// this probably is never called:
- (void)cancelEchoOperations: (BOOL)explicit;
{
[ self.commandOperationQueue cancelAllOperations ];

}

Any ideas how to debug this?

Gerriet.


_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.ne
Ken Thomases
2017-03-27 03:39:01 UTC
Permalink
Post by Gerriet M. Denkmann
macOS 12.3
Thread 12 Crashed:: Dispatch queue: เสือ :: NSOperation 0x61800184fbd0 (QOS: UTILITY)
0 libsystem_kernel.dylib 0x00007fffb3d65dd6 __pthread_kill + 10
1 libsystem_pthread.dylib 0x00007fffb3e51787 pthread_kill + 90
2 libsystem_c.dylib 0x00007fffb3ccb420 abort + 129
3 libc++abi.dylib 0x00007fffb282885a abort_message + 266
4 libc++abi.dylib 0x00007fffb284dc4f default_terminate_handler() + 267
5 libobjc.A.dylib 0x00007fffb3357b8e _objc_terminate() + 103
6 libc++abi.dylib 0x00007fffb284ad69 std::__terminate(void (*)()) + 8
7 libc++abi.dylib 0x00007fffb284ade3 std::terminate() + 51
8 libdispatch.dylib 0x00007fffb3c010cc _dispatch_client_callout + 28
9 libdispatch.dylib 0x00007fffb3c17ae5 _dispatch_queue_serial_drain + 896
10 libdispatch.dylib 0x00007fffb3c09cd9 _dispatch_queue_invoke + 1046
11 libdispatch.dylib 0x00007fffb3c02e70 _dispatch_root_queue_drain + 476
12 libdispatch.dylib 0x00007fffb3c02c47 _dispatch_worker_thread3 + 99
13 libsystem_pthread.dylib 0x00007fffb3e4e712 _pthread_wqthread + 1299
14 libsystem_pthread.dylib 0x00007fffb3e4e1ed start_wqthread + 13
I would expect that some message would be logged to the system log at the time of the crash and/or included in the crash report, just above the thread backtraces. Was there such a message? If so, what was it?

Regards,
Ken


_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.net
Gerriet M. Denkmann
2017-03-27 05:04:44 UTC
Permalink
Post by Ken Thomases
Post by Gerriet M. Denkmann
macOS 12.3
Thread 12 Crashed:: Dispatch queue: เสือ :: NSOperation 0x61800184fbd0 (QOS: UTILITY)
0 libsystem_kernel.dylib 0x00007fffb3d65dd6 __pthread_kill + 10
1 libsystem_pthread.dylib 0x00007fffb3e51787 pthread_kill + 90
2 libsystem_c.dylib 0x00007fffb3ccb420 abort + 129
3 libc++abi.dylib 0x00007fffb282885a abort_message + 266
4 libc++abi.dylib 0x00007fffb284dc4f default_terminate_handler() + 267
5 libobjc.A.dylib 0x00007fffb3357b8e _objc_terminate() + 103
6 libc++abi.dylib 0x00007fffb284ad69 std::__terminate(void (*)()) + 8
7 libc++abi.dylib 0x00007fffb284ade3 std::terminate() + 51
8 libdispatch.dylib 0x00007fffb3c010cc _dispatch_client_callout + 28
9 libdispatch.dylib 0x00007fffb3c17ae5 _dispatch_queue_serial_drain + 896
10 libdispatch.dylib 0x00007fffb3c09cd9 _dispatch_queue_invoke + 1046
11 libdispatch.dylib 0x00007fffb3c02e70 _dispatch_root_queue_drain + 476
12 libdispatch.dylib 0x00007fffb3c02c47 _dispatch_worker_thread3 + 99
13 libsystem_pthread.dylib 0x00007fffb3e4e712 _pthread_wqthread + 1299
14 libsystem_pthread.dylib 0x00007fffb3e4e1ed start_wqthread + 13
I would expect that some message would be logged to the system log at the time of the crash and/or included in the crash report, just above the thread backtraces. Was there such a message? If so, what was it?
Yes, you are right. And I have to apologise for not spotting this:

*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** setObjectForKey: object cannot be nil (key: SortedKeys.plist)'
abort() called

and the really relevant backtrace is:

Application Specific Backtrace 1:
0 CoreFoundation 0x00007fff9e6c40db __exceptionPreprocess + 171
1 libobjc.A.dylib 0x00007fffb3355a2a objc_exception_throw + 48
2 CoreFoundation 0x00007fff9e5c4115 -[__NSDictionaryM setObject:forKey:] + 1061
3 Foundation 0x00007fffa02bf805 -[NSRTFD setObject:forKey:] + 257
4 Foundation 0x00007fffa02b94ee -[NSFileWrapper _newImpl] + 573
5 Foundation 0x00007fffa02b9811 -[NSFileWrapper serializedRepresentation] + 37


My app does (in some non-main thread used by my Dispatch queue: เสือ):

NSString *directoryPath = …
… write some files to directoryPath and finally do:
[ arrayOfStrings writeToFile: “directoryPath/SortedKeys.plist” atomically: YES ]; ← pseudo code

NSURL *url = [ NSURL fileURLWithPath: directoryPath isDirectory: YES ];
NSFileWrapper *fw = [ [ NSFileWrapper alloc ] initWithURL: url options: 0 error: &outError ];
… remove a few subwrappers from fw …

NSData *dataIn = fw.serializedRepresentation; ← crashed here

I suspect that this might be a rare timing issue, i.e. SortedKeys.plist has not been fully written when serializedRepresentation is called.

Any ideas how this could be avoided?

Kind regards,

Gerriet.



_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.n
Jens Alfke
2017-03-27 16:37:21 UTC
Permalink
Post by Gerriet M. Denkmann
*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** setObjectForKey: object cannot be nil (key: SortedKeys.plist)'
I recommend always having an exception breakpoint set, to catch things like this.
Post by Gerriet M. Denkmann
I suspect that this might be a rare timing issue, i.e. SortedKeys.plist has not been fully written when serializedRepresentation is called.
Is the snippet you posted all code running in the same thread/queue? If so, there couldn’t be a race condition between writing the plist and reading it. If not, you need some synchronization between the two operations (the specifics would depend on the details of your program.)

—Jens
_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.net

This email sent t
Gerriet M. Denkmann
2017-03-28 03:25:31 UTC
Permalink
Sent from my iPhone
Post by Jens Alfke
Post by Gerriet M. Denkmann
*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** setObjectForKey: object cannot be nil (key: SortedKeys.plist)'
I recommend always having an exception breakpoint set, to catch things like this.
This same error occurred twice within 250 days. Running the code for about a year in Xcode is really not feasible.
Post by Jens Alfke
Post by Gerriet M. Denkmann
I suspect that this might be a rare timing issue, i.e. SortedKeys.plist has not been fully written when serializedRepresentation is called.
Is the snippet you posted all code running in the same thread/queue? If so, there couldn’t be a race condition between writing the plist and reading it.
Yes, all is running in the same thread.

If no race condition (and I agree that there should be none) what else could be causing this?

Kind regards,

Gerriet

_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.na
Jens Alfke
2017-03-28 03:32:22 UTC
Permalink
Post by Gerriet M. Denkmann
Sent from my iPhone
Post by Jens Alfke
Post by Gerriet M. Denkmann
*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** setObjectForKey: object cannot be nil (key: SortedKeys.plist)'
I recommend always having an exception breakpoint set, to catch things like this.
This same error occurred twice within 250 days. Running the code for about a year in Xcode is really not feasible.
But when it did occur, it was hard to figure out what was going on, right? So if you have the breakpoint already there, then instead of crashing you stop at the breakpoint, which is much easier to debug.
Post by Gerriet M. Denkmann
If no race condition (and I agree that there should be none) what else could be causing this?
Dunno. It’s somewhere inside Foundation code. If you have the backtrace, looking at the method names can be a clue sometimes.

—Jens

_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.net

This email sent to ***@ml-
Gerriet M. Denkmann
2017-03-28 03:50:43 UTC
Permalink
Sent from my iPhone
Post by Jens Alfke
Post by Gerriet M. Denkmann
Sent from my iPhone
Post by Jens Alfke
Post by Gerriet M. Denkmann
*** Terminating app due to uncaught exception 'NSInvalidArgumentException', reason: '*** setObjectForKey: object cannot be nil (key: SortedKeys.plist)'
I recommend always having an exception breakpoint set, to catch things like this.
This same error occurred twice within 250 days. Running the code for about a year in Xcode is really not feasible.
But when it did occur, it was hard to figure out what was going on, right?
No, not really. It was just my stupidity of reading the crash log right.

It clearly showed that it crashed when I asked a Filewrapper (which contains about 6 sub wrappers which represent files) for serialised data.

And one of these subwrappers (which were being put into an NSDictionary) turned out to be nil.

Kind regards,

Gerriet

_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.net

This email sent to ***@ml-in.narkive.net
Quincey Morris
2017-03-28 04:41:46 UTC
Permalink
Post by Gerriet M. Denkmann
[ arrayOfStrings writeToFile: “directoryPath/SortedKeys.plist” atomically: YES ]; ← pseudo code
A couple of points about this line of code, assuming that the method -[NSArray writeToFile:atomically:] is actually being used:

1. This method has a YES/NO result, which you really shouldn’t ignore, if you do.

2. This method is a file API with no outError parameter. All such methods should be regarded as ancient, undesirable to use, and superseded by a newer method that does have an outError parameter. The fact that there is no newer method with an outError parameter tells you that Apple has (essentially) abandoned this method, and that the replacement API requires a different approach. My guess is that the intended replacement is to convert the NSArray to a NSData object yourself (through serialization, archiving, or some similar technique), and then using one of the more modern NSData file writing methods to get it onto disk.

3. Really, don’t use path-based methods any more. Use the URL-based variant. (In this case, there is one, but it’s also lacking an outError parameter, so it also should be abandoned.)

However, none of the above can explain your crash. The symptoms of the crash indicate that the directory listed a file called “SortedKeys.plist”, but the file didn’t actually exist (or couldn’t be read), which is on the face of it pretty weird. That leads me to:

4. You might use “atomically: NO” instead of “atomically: YES”. It’s not clear whether you expect “SortedKeys.plist” to exist already in the directory, but I’m guessing not, or that you could delete it manually first. If the file doesn’t exist, and if you change your code to capture and handle file-write errors properly, then writing atomically doesn’t have any value, and it may in rare cases turn out to be actively harmful.

A successful non-atomic write is an open/write/close sequence. An atomic write does that to a temp location on the same HFS volume, then does a file system atomic “swap” operation to exchange the data of the real and temp files. On a non-local (e.g. network) or non-HFS volume, the file manager may not have access to an atomic file swap, so might have to simulate with renames, moves and/or copies.

So, an atomic file write involves a longer, possibly quite a lot longer, sequence of file system operations, and it’s not totally outside the bounds of possibility that there might be some reordering between this sequence and other sequences, perhaps even the subsequent directory scan that you do. It doesn’t seem outside the bounds of possibility that the directory scan might see the directory in a transitional state.

This is highly speculative, and other people may have reasons to argue that such a reordering cannot legally take place, but if you use a non-atomic write you eliminate any possible timing window on the directory scan, I think.

That doesn’t really touch the “how to debug?” question, to which I don’t know the answer, except to suggest you play around trying to make the problem more reproducible.

_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.net

T
Gerriet M. Denkmann
2017-03-28 06:46:19 UTC
Permalink
Sent from my iPhone
Post by Quincey Morris
Post by Gerriet M. Denkmann
[ arrayOfStrings writeToFile: “directoryPath/SortedKeys.plist” atomically: YES ]; ← pseudo code
1. This method has a YES/NO result, which you really shouldn’t ignore, if you do.
I use the result to print an error message. But you are right: I should abandon the whole operation in case of error.
Post by Quincey Morris
2. This method is a file API with no outError parameter. All such methods should be regarded as ancient, undesirable to use, and superseded by a newer method that does have an outError parameter. The fact that there is no newer method with an outError parameter tells you that Apple has (essentially) abandoned this method, and that the replacement API requires a different approach. My guess is that the intended replacement is to convert the NSArray to a NSData object yourself (through serialization, archiving, or some similar technique), and then using one of the more modern NSData file writing methods to get it onto disk.
As the array in question contains strings, none of which should contain a \n I was thinking of converting it into a string, which would then written as UTF16 (which would have the further advantage of reducing the size to about 40%).
Post by Quincey Morris
3. Really, don’t use path-based methods any more. Use the URL-based variant. (In this case, there is one, but it’s also lacking an outError parameter, so it also should be abandoned.)
4. You might use “atomically: NO” instead of “atomically: YES”. It’s not clear whether you expect “SortedKeys.plist” to exist already in the directory, but I’m guessing not, or that you could delete it manually first. If the file doesn’t exist, and if you change your code to capture and handle file-write errors properly, then writing atomically doesn’t have any value, and it may in rare cases turn out to be actively harmful.
There probably will exist an old, not up to date version already.
Post by Quincey Morris
A successful non-atomic write is an open/write/close sequence. An atomic write does that to a temp location on the same HFS volume, then does a file system atomic “swap” operation to exchange the data of the real and temp files. On a non-local (e.g. network) or non-HFS volume, the file manager may not have access to an atomic file swap, so might have to simulate with renames, moves and/or copies.
So, an atomic file write involves a longer, possibly quite a lot longer, sequence of file system operations, and it’s not totally outside the bounds of possibility that there might be some reordering between this sequence and other sequences, perhaps even the subsequent directory scan that you do. It doesn’t seem outside the bounds of possibility that the directory scan might see the directory in a transitional state.
This is highly speculative, and other people may have reasons to argue that such a reordering cannot legally take place, but if you use a non-atomic write you eliminate any possible timing window on the directory scan, I think.
I will abandon the atomic write and just rely on the outcome of the write.
If it fails I have no interest in this file at all - the old version is useless anyway.
Post by Quincey Morris
That doesn’t really touch the “how to debug?” question, to which I don’t know the answer, except to suggest you play around trying to make the problem more reproducible.
This is my real problem: so far I have seen this error twice - within 250 days. Using the app several times per day.

If I could reproduce the error I am confident of fixing it.

I was suspecting a relation with sleep - the first time it occurred at 3:00 (computer should be sleeping) the second time at 17:00 (unlikely to be sleeping, but I'm not sure)

Thanks for your suggestions!

Kind regards

Gerriet


_______________________________________________

Cocoa-dev mailing list (Cocoa-***@lists.apple.com)

Please do not post admin requests or moderator comments to the list.
Contact the moderators at cocoa-dev-admins(at)lists.apple.com

Help/Unsubscribe/Update your Subscription:
https://lists.apple.com/mailman/options/cocoa-dev/gegs%40ml-in.narkive.net

This email sent to ***@ml-in.narkiv

Continue reading on narkive:
Loading...