Hi Jason

I haven't attempted to debug your code but I use NSTask extensively and have 
experienced some of the problems you describe.

In each case I was not correctly handling the asynchronous availability of data 
in the pipe ie: there is nothing wrong with the approach but implementation is 
all.

In my case I found that the implementation detailed in the following sample 
worked with great reliability on GC apps (search the xcode docs):

CommandLineToolPlugin.m 

This sample uses NSFileHandle - waitForDataInBackgroundAndNotify.
This generates a single notification with all the available data - which may or 
may not be suitable for your needs.

The sample above calls NSTask - waitUntilExit but that is only a detail I think.

If this was my project I would instigate a branch that implemented the approach 
detailed in CommandLineToolPlugin.m and see where that got me.
It should have fewer moving parts at least.

Regards

Jonathan Mitchell

Developer
Mugginsoft LLP
http://www.mugginsoft.com







On 17 Mar 2011, at 09:01, Jason Harris wrote:

> General Problem:
> ------------------------------------
> NSTask is most of the time working for me, but intermittently it's failing to 
> return results. Either the result is silently dropped, or more infrequently I 
> am getting exceptions in:
> 
> [NSConcreteData initWithBytes:length:copy:freeWhenDone:bytesAreVM:] or
> [NSConcreteFileHandle availableData] or
> [NSConcreteFileHandle readDataOfLength:]
> 
> depending on the tweaks / experiments I am attempting to play with.
> 
> If MacHg issues the *exact* same command a little later it will work.
> 
> 
> 
> Background:
> ------------------------------------
> I write MacHg an open source OSX multithreaded GUI client for Mercurial. I 
> have wanted to move to showing progress bars in MacHg as Mercurial progresses 
> in doing its long running operations.
> 
> In all my released versions of MacHg so far I have used only the 
> readDataToEndOfFileIgnoringErrors approach to NSTask (since once I launch a 
> task I am only ever reading data from it, and not actually ever sending data 
> to its stdin). Ie something like:
> 
>   NSData* outData = [[outPipe fileHandleForReading] 
> readDataToEndOfFileIgnoringErrors]
>   NSData* errData = [[errPipe fileHandleForReading] 
> readDataToEndOfFileIgnoringErrors];
> 
> However, I have previously had problems with intermittent exceptions of 
> [NSConcreteFileHandle readDataOfLength:] which bugged me. I spent some time 
> trying to fix these but in the end couldn't figure out what was going wrong / 
> how to fix them properly. In the end I used the bandaided approach of: 
> http://www.cocoabuilder.com/archive/cocoa/173348-nstask-stealth-bug-in-readdataoflength.html#173647
> 
> (Of note I have Garbage collection turned on in the MacHg project.)
> 
> 
> 
> Moving to Notification based NSTask:
> ------------------------------------
> But it has nagged me as to why this was occurring using 
> readDataToEndOfFileIgnoringErrors.  In any case I had thought moving to a 
> "Moriarity" style NSTask usage was going to solve my problems. I have now 
> coded a "Moriarity" style NSTask usage up in MacHg. Ie using 
> NSFileHandleReadCompletionNotification and NSTaskDidTerminateNotification. 
> However, I discovered that the frequency of odd behavior has actually 
> increased not decreased in moving to this approach.
> 
> I have looked at (in fact studied in detail) the source code for Moriarity, 
> AMShellWrapper, MyTask, and OpenFileKiller. 
> (http://cocoadev.com/index.pl?NSTask ) (I have not really covered looking at 
> MFTask, or trying to use Pseudo-TTYs or fork(), exec(), popen(), pipe() sorts 
> of low level unix / posix things.)
> 
> The hart of the code is the following (Note there are currently things in the 
> code which won't be in the production code since they are used for debugging. 
> Eg, the member theShellTask_ of ExecutionResult will be ripped out for 
> production.)
> 
> 
> 
> The Relevant Code:
> ------------------------------------
> 
> - (void) setPendingTermination
> {
>    pendingTermination_ = YES;
>    [NSObject cancelPreviousPerformRequestsWithTarget:self  
> selector:@selector(finishUp)  object:nil];
>    [self performSelector:@selector(finishUp)  withObject:nil  
> afterDelay:10.0];
> }
> 
> - (void) resetPendingTermination
> {
>    [NSObject cancelPreviousPerformRequestsWithTarget:self  
> selector:@selector(finishUp)  object:nil];
>    pendingTermination_ = NO;
> }
> 
> - (id) initWithCommand:(NSString*)cmd andArgs:(NSArray*)args 
> onTask:(NSTask*)task
> {    
>    generatingCmd_ = cmd;
>    generatingArgs_ = args;
>    task_ = task ? task : [[NSTask alloc] init];
> 
>    outPipe_    = [[NSPipe alloc] init];     // Create the pipe to write 
> standard out to
>    errPipe_    = [[NSPipe alloc] init];     // Create the pipe to write 
> standard error to
>    outHandle_  = [outPipe_ fileHandleForReading];
>    errHandle_  = [errPipe_ fileHandleForReading];
>    outputData_ = [[NSMutableData alloc] init];
>    errorData_  = [[NSMutableData alloc] init];
> 
>    [task_ setLaunchPath:cmd];
>    [task_ setArguments:args];
>    [task_ setStandardInput:[NSPipe pipe]];
>    [task_ setStandardOutput:outPipe_];
>    [task_ setStandardError:errPipe_];
> 
>    [self observe:NSFileHandleReadCompletionNotification from:outHandle_    
> byCalling:@selector(gotOutput:)];
>    [self observe:NSFileHandleReadCompletionNotification from:errHandle_    
> byCalling:@selector(gotError:)];
>    [self observe:NSTaskDidTerminateNotification         from:task_            
> byCalling:@selector(gotExit:)];
> 
>    [outHandle_ readInBackgroundAndNotify];
>    [errHandle_ readInBackgroundAndNotify];
>    isFinished_            = NO;
>    pendingTermination_ = NO;
> 
>    return self;
> }
> 
> - (void) gotOutput:(NSNotification*)notification
> {
>    NSData* data = [notification.userInfo 
> objectForKey:NSFileHandleNotificationDataItem];
>    if (notification.object == outHandle_)
>    {
>        if (data.length > 0)
>        {
>            DebugLog(@"...got Output for %@ ...", [self commandLineString]);
>            [outHandle_ readInBackgroundAndNotify];
>            [outputData_ appendData:data];
>            [self resetPendingTermination];
>        }
>        else
>        {
>            DebugLog(@"...got NULL standard Output for %@ ...", [self 
> commandLineString]);
>            outHandle_ = nil;
>            if ([self shouldFinishUp])
>                [self finishUp];
>        }
>    }
> }
> 
> - (void) gotError:(NSNotification*)notification
> {
>    if (notification.object == errHandle_)
>    {
>        NSData* data = [notification.userInfo 
> objectForKey:NSFileHandleNotificationDataItem];
>        if (data.length > 0)
>        {
>            DebugLog(@"...got Error for %@ ...", [self commandLineString]);
>            [errHandle_ readInBackgroundAndNotify];
>            if (!arrayOfErrorData_)
>                arrayOfErrorData_ = [[NSMutableArray alloc]init];
>            [arrayOfErrorData_ addObject:data];
>            [errorData_ appendData:data];
>            [self resetPendingTermination];
>        }
>        else
>        {
>            DebugLog(@"...got NULL Error Output for %@ ...", [self 
> commandLineString]);
>            errHandle_ = nil;
>            if ([self shouldFinishUp])
>                [self finishUp];
>        }
>    }
> }
> 
> - (void) gotExit:(NSNotification*)notification
> {
>    if ([self shouldFinishUp])
>        [self finishUp];
>    else
>        [self setPendingTermination];
> }
> 
> 
> - (BOOL) shouldFinishUp
> {
>    return ![task_ isRunning] && !outHandle_ && !errHandle_;
> }
> 
> - (void) finishUp
> {
>    if (isFinished_)
>        return;
> 
>    DebugLog(@"...Finishing up for %@ ...", [self commandLineString]);
> 
>    [NSObject cancelPreviousPerformRequestsWithTarget:self  
> selector:@selector(finishUp)  object:nil];
>    [self stopObserving:NSFileHandleReadCompletionNotification from:nil];
>    [self stopObserving:NSTaskDidTerminateNotification from:nil];
> 
>    [task_ terminate];
> 
>    // Clear standard out and standard error
>    NSData* data;
>    while ((data = [outHandle_ availableDataIgnoringErrors]) && [data length])
>        [outputData_ appendData:data];    
>    while ((data = [errHandle_ availableDataIgnoringErrors]) && [data length])
>        [errorData_ appendData:data];
> 
>    outHandle_ = nil;
>    errHandle_ = nil;
>    result_ = [task_ terminationStatus];
>    isFinished_ = YES;    
> }
> 
> 
> - (NSString*) commandLineString
> {
>    NSMutableString* desc = [NSMutableString stringWithString:[generatingCmd_ 
> lastPathComponent]];
>    for (NSString* arg in generatingArgs_)
>    {
>        [desc appendString:@" "];
>        [desc appendString:arg];
>    }
>    return desc;
> }
> 
> 
> - (BOOL) waitTillFinished
> {
>    // wait for task to exit:
>    while (![self shouldFinishUp])
>    {
>        // If the task is terminated we should set up a pending termination 
> which will terminate in a bit. This catches some
>        // zombie NSTasks where either the outputData or errorData of 0 were 
> never posted..
>        BOOL terminated = ![task_ isRunning];
>        if (terminated && !pendingTermination_)
>        {
>            DebugLog(@"...Found terminated for %@ ...", [self 
> commandLineString]);
>            [self setPendingTermination];
>        }
> 
>        BOOL runLoopRan = [[NSRunLoop currentRunLoop] 
> runMode:NSDefaultRunLoopMode beforeDate:[NSDate distantFuture]];
>        if (!runLoopRan)
>            break;
>        if (!isFinished_)
>            DebugLog(@"...waitTillFinished still waiting for %@ ...", [self 
> commandLineString]);
>    }
> 
>    [self finishUp];
>    DebugLog(@"...Exiting waitTillFinished for %@ ...", [self 
> commandLineString]);
>    return (result_ == 0);
> }
> 
> 
> + (ExecutionResult*) execute:(NSString*)cmd withArgs:(NSArray*)args 
> onTask:(NSTask*)task
> {
>    ShellTask* shellTask = [[ShellTask alloc] initWithCommand:cmd andArgs:args 
> onTask:task];
> 
>    [shellTask->task_ launch];            // Start the process
>    DebugLog(@"launched %@", [shellTask commandLineString]);
> 
>    [shellTask waitTillFinished];
> 
>    DebugLog(@"Finished execute cmd for %@", [shellTask commandLineString]);
> 
>    NSString* outStr = [[NSString alloc] initWithData:shellTask->outputData_ 
> encoding:NSUTF8StringEncoding];
>    NSString* errStr = [[NSString alloc] initWithData:shellTask->errorData_  
> encoding:NSUTF8StringEncoding];
>    ExecutionResult* result = [ExecutionResult resultWithCmd:cmd args:args 
> result:shellTask->result_ outStr:outStr errStr:errStr];
>    result->theShellTask_ = shellTask;
>    return result;
> }
> 
> 
> ------------------------------------
> 
> The complete code is on bitbucket (MacHg is open source and I welcome 
> contributions :) ) 
> https://bitbucket.org/jfh/machg/src/cae197d03665/Classes/General/TaskExecutions.m
> 
> If you are going the extra mile, building MacHg is quite simple. You need to 
> (1) clone the repository to your local machine, (2) Double click the IB 
> plugin MacHg/LinkedLibraries/BWToolkit/BWToolkit.ibplugin, (3) Compile and 
> run. Note I have only tested MacHg with XCode 3.2 and not 4.0 yet. (See 
> https://bitbucket.org/jfh/machg/wiki/Compiling.wiki) (If you are debugging 
> this you might find it helpful to return directly from 
> computeIncomingOutgoingToCompatibleRepositories so you don't see all the 
> NSTask traffic to do with figuring out the incoming and outgoing statuses for 
> the repositories.)
> 
> So with all the debugging in place, when things fail, it looks like the task 
> launches and then immediately exits. Eg here is a small transcript:
> 
> BAD:
> --------
> 0x1014810/-[MacHgDocument initializeRepositoryData] Initializing log entry 
> collection
> 0x1250100/+[ShellTask execute:withArgs:onTask:]    launched localhg 
> combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/RhodeCode
> 0x1250100/-[ShellTask gotExit:]                    ...got Exit for localhg 
> combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/RhodeCode ...
> 0x1250100/-[ShellTask gotError:]                   ...got NULL Error Output 
> for localhg combinedinfo --cwd 
> /Volumes/QuickSilver/Development/sandbox/RhodeCode ...
> 0x1250100/-[ShellTask waitTillFinished]            ...waitTillFinished still 
> waiting for localhg combinedinfo --cwd 
> /Volumes/QuickSilver/Development/sandbox/RhodeCode ...
> 0x1250100/-[ShellTask finishUp]                    ...Finishing up for 
> localhg combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/RhodeCode 
> ...
> 
> (Note how the first notification in the task which was received was the exit, 
> then Null for the error was received, and then the task exited without ever 
> sending anything for the output.) Normally this should be something like:
> 
> GOOD:
> --------
> 0x1014810/-[MacHgDocument initializeRepositoryData] Initializing log entry 
> collection
> 0x1250100/+[ShellTask execute:withArgs:onTask:]    launched localhg 
> combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/wiki
> 0x1250100/-[ShellTask gotOutput:]                  ...got Output for localhg 
> combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/-[ShellTask waitTillFinished]            ...waitTillFinished still 
> waiting for localhg combinedinfo --cwd 
> /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/-[ShellTask gotOutput:]                  ...got NULL standard 
> Output for localhg combinedinfo --cwd 
> /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/-[ShellTask gotExit:]                    ...got Exit for localhg 
> combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/-[ShellTask waitTillFinished]            ...waitTillFinished still 
> waiting for localhg combinedinfo --cwd 
> /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/-[ShellTask gotError:]                   ...got NULL Error Output 
> for localhg combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/wiki 
> ...
> 0x1250100/-[ShellTask finishUp]                    ...Finishing up for 
> localhg combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/-[ShellTask waitTillFinished]            ...Exiting 
> waitTillFinished for localhg combinedinfo --cwd 
> /Volumes/QuickSilver/Development/sandbox/wiki ...
> 0x1250100/+[ShellTask execute:withArgs:onTask:]    Finished execute cmd for 
> localhg combinedinfo --cwd /Volumes/QuickSilver/Development/sandbox/wiki
> 0x1014810/__-[RepositoryData 
> loadCombinedInformationAndNotify:]_block_invoke_2 finished 
> loadCombinedInformationAndNotify
> 
> Now a couple things to note is that if the   [self 
> performSelector:@selector(finishUp)  withObject:nil  afterDelay:10.0]    
> fires in the BAD case then the outer call to waitTillFinished just sort of 
> vanishes, since there is always a DebugLog call which prints "...Exiting 
> waitTillFinished for ..." but is can be seen in the BAD transcript this just 
> isn't present.
> 
> Here is a screen shot of the exception to do with concrete file problem. (In 
> this case *** -[NSConcreteFileHandle availableData]: Bad file descriptor. In 
> either the case BAD above or in the exception case if I step with a debugger 
> up through the code then when it hits the __CFRunLoopRun at stack level 8 
> below then single stepping causes the debugger to act like I hit continue 
> instead of step over and then it looks like its ignoring waitTillFinished and 
> just sort of jumping out.
> 
> <PastedGraphic-1.png>
> 
> 
> You only need a couple of repositories to show this problem. Eg if you create 
> a new document in MacHg and then add say the following three test 
> repositories to the document (You can clone them from within MacHg or the 
> command line, it doesn't matter)
> 
> https://time-tracker-mac.googlecode.com/hg/
> http://bitbucket.org/marcinkuzminski/rhodecode
> https://bitbucket.org/jfh/machg
> 
> Then just click on one, then the next, then the third, then back to the first 
> and pretty soon you will hit a case when the files don't update in the 
> display. This happens because the NSTask just dropped the result / failed.
> 
> I have experimented with lots of different variations, ie dropping the 
> pending terminations, listing in different modes, keeping outPipe_, and 
> errPipe_ as members just to ensure they can't possibly be collected, etc, 
> etc. All to no avail. (I am happy to make a short screen capture movie of the 
> behavior or make more screen shots but this email is already long enough...)
> 
> If anybody can shed some light on anything which is going on here... Or at 
> least avenues to explore I would be very grateful.... (And sorry for the long 
> email...)
> 
> Thanks,
>   Jason_______________________________________________
> 
> Cocoa-dev mailing list ([email protected])
> 
> 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:
> http://lists.apple.com/mailman/options/cocoa-dev/jonathan%40mugginsoft.com
> 
> This email sent to [email protected]

_______________________________________________

Cocoa-dev mailing list ([email protected])

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:
http://lists.apple.com/mailman/options/cocoa-dev/archive%40mail-archive.com

This email sent to [email protected]

Reply via email to