NSPipe/NSFileHandle file descriptors never freed

Originator:valexa
Number:rdar://10257191 Date Originated:10-Oct-2011 01:55 AM
Status:open Resolved:
Product:Mac OS X Product Version:10.7.1
Classification: Reproducible:Always
 
Summary:

a NSPipe seems to be always over retained, it never gets deallocated and the pipe stays in use, additionally when the maximum kern.maxfilesperproc is reached [NSPipe pipe] silently starts returning nil , project attached.

Steps to Reproduce:

    for (int i=0; i < 5000; i++) {
        NSPipe *pipe = [[NSPipe alloc] init];
        if (pipe == nil) {
            NSLog(@"ERROR ran out of file descriptors after %@i",i);
            break;
        }   
        NSTask *task = [[NSTask alloc] init];
        [task setLaunchPath:@"/usr/bin/who"];
        [task setStandardOutput:pipe];        
        [task launch];
        //NSFileHandle *file = [pipe fileHandleForReading];  //optional        
        //[file availableData];                             //optional
        [task waitUntilExit];
        //[file closeFile]; fix to close the pipe even if documentation states different
        [pipe release];
        [task release];
        if (i % 100 == 0) {
            NSLog(@"%i pipes leaked",i);            
        }
    }

Expected Results:

not have to call closeFile as documented

Actual Results:

have to call closeFile else the pipes never get freed

Regression:

Notes:

Comments

Source Tree Still Broken

It's April 2023 and this is still an issue in macOS Ventura 13.3.1 (22E261) on a Mac Studio with 128 GB or RAM.

By bhuebscher at April 13, 2023, 4:09 p.m. (reply...)

Atlassian genuine approach to blame Apple

Based on the fact that so far SourceTree was the only application I would say that they are using this bug as a scapegoat.

They even closed their own issue as resolved as https://jira.atlassian.com/browse/SRCTREE-4196

By sorin.sbarnea at Jan. 18, 2019, 11:38 a.m. (reply...)

This error is a big fail, since, instead of warning once, it warn in a while, look at this :

https://imgur.com/a/pzPWh8S

Who does this kind of UX in 2018 :'(

By david.babel at Nov. 26, 2018, 10:52 a.m. (reply...)

I got it too even with beta of SourceTree 3.0 ...

By sorin.sbarnea at Oct. 9, 2018, 2:35 p.m. (reply...)

I got it too on High Sierra 10.13.6, Source Tree: 2.7.6 (177).

WTF? 7 years passed and still nothing works

By gerchicov.bp at July 31, 2018, 1:09 p.m. (reply...)

Still seeing this too. Even though sourcetree claims it's not responsible in the error, it unfortunately is. This generally happens after having Sourcetree open for a few days, and happened on both Sierra and El Capitan.

Anyone encountering this, to see the number of open files and which process is responsible, run this in your terminal:

lsof |cut -b1-16|sort|uniq -c|sort -n | head -n 5

And you'll get the top 5 of apps using file descriptors:

4655 SourceTre 7898

667 Google 1624

379 Finder 445

375 Dropbox 455

336 Adobex20 504

SourceTree has 4655 open files (7898 is the process id)

Inspect shows a lot of files like this open:

/private/var/folders/by/v9dvftg10d96q25k8jl82k5c0000gn/T/whtree_modules_tollium_include_internal_langedit_langeditor_Before_3aab43a2e547a942dc1bbeba27cf4d9036c3fee8.whlib

The names between /T/ and Before match the paths of files iny my repository, and I see many of these files being opened multiple times

Wrap the inner loop with an @autoreleasepool - the hundreds of pipe "leaks" go away.

Here's a complete program to try.

Run it without the autorelease pool, and the "newly opened fd" will increase by a hundred each time. Put in the autorelease pool, and that value will increase by 1 every 100 loops, which is because "/" is opened but never closed.

open() will always give you the lowest available file descriptor, so if those are getting leaked by the bucketful, then the fd returned by open will also be increasing.

Looks like NSTask and friends are using autoreleased objects and cleaning them at dealloc time (which is reasonable). Most cocoa applications that use NSTask do so frm the main thread (since it's async), and the main thread drains the autorelease pool after every event, so this shouldn't be an issue in real life.

If you're on a background thread spinning doing lots of tasks without ever draining the autorelease pool, it could seem like the toolkit is leaking,

#import <Foundation/Foundation.h>

// clang -g -Wall -framework Foundation -o pipeleak pipeleak.m

// http://openradar.appspot.com/radar?id=1387401

int main() {
    for (int i=0; i < 5000; i++) {
        @autoreleasepool {
            NSPipe *pipe = [[NSPipe alloc] init];
            if (pipe == nil) {
                NSLog(@"ERROR ran out of file descriptors after %d",i);
                break;
            }

            NSTask *task = [[NSTask alloc] init];
            [task setLaunchPath:@"/usr/bin/who"];
            [task setStandardOutput:pipe];
            [task launch];

            //NSFileHandle *file = [pipe fileHandleForReading];  //optional
            //[file availableData];                             //optional
            [task waitUntilExit];

            //[file closeFile]; fix to close the pipe even if documentation states different
            [pipe release];
            [task release];

            if (i % 100 == 0) {
                int fd = open("/", O_RDONLY);
                NSLog(@"after %d loops, newly opened fd is %d", i, fd);
                // NSLog(@"%i pipes leaked",i);
            }
        }
    }
    return 0;
} // main

I currently have this running for 500,000. I also have sysctl kern.maxfiles of 12288 (kern.maxfilesperproc of 10240). I've passed 12300 loops, so even if a file descriptor was leaking and I didn't notice it, the world should have ended.

(couple of hours elapse)

2017-01-11 14:50:06.542 pipeleak[36236:2635131] after 0 loops, newly opened fd is 4
2017-01-11 14:50:13.200 pipeleak[36236:2635131] after 100 loops, newly opened fd is 4
2017-01-11 14:50:19.798 pipeleak[36236:2635131] after 200 loops, newly opened fd is 4
....
2017-01-11 21:36:36.302 pipeleak[36236:2635131] after 132700 loops, newly opened fd is 4
2017-01-11 21:36:42.915 pipeleak[36236:2635131] after 132800 loops, newly opened fd is 4
2017-01-11 21:36:49.559 pipeleak[36236:2635131] after 132900 loops, newly opened fd is 4
...

Takes about six seconds to do 100 of them.

After some time, and a couple of laptop sleeps later, it completed all of them:

2017-01-12 16:36:51.348 pipeleak[36236:2635131] after 499700 loops, newly opened fd is 4
2017-01-12 16:36:57.888 pipeleak[36236:2635131] after 499800 loops, newly opened fd is 4
2017-01-12 16:37:04.443 pipeleak[36236:2635131] after 499900 loops, newly opened fd is 4

Thank you for pointing this out Mark, I've slotted it into SourceTree's next sprint so we can finally handle this reasonably. I created a CLI macOS project in Xcode 8.2.1 on 10.11.6 (15G1421) and copied this code into the main file for testing out various scenarios we use. Here's what I'm seeing though right out of the box…

2017-03-29 19:17:22.021 test[33262:725573] after 0 loops, newly opened fd is 5

2017-03-29 19:17:28.609 test[33262:725573] after 100 loops, newly opened fd is 6

2017-03-29 19:17:35.183 test[33262:725573] after 200 loops, newly opened fd is 7

2017-03-29 19:17:41.756 test[33262:725573] after 300 loops, newly opened fd is 8

2017-03-29 19:17:48.388 test[33262:725573] after 400 loops, newly opened fd is 9

2017-03-29 19:17:55.008 test[33262:725573] after 500 loops, newly opened fd is 10

Are you seeing the same results?

By bganninger at March 30, 2017, 2:23 a.m. (reply...)

I'll give it a whirl!

Is there any way to see what is opening and not closing them? Is there any way to determine the number allowed?

Source Tree again

Running under Sierra 10.12.1 (16B2555) Many, many commits.

Please note: Force quitting Sourcetree cleared the issue. So, it's more likely a Sourcetree issue at this point, not an OS issue.

By lordandrei at Nov. 16, 2016, 3:31 p.m. (reply...)

+1

Running into this on Sierra using SourceTree

+1

Continuously getting this in Sierra using Sourcetree when doing lots of commits. I'm especially using the Stage Hunk option on a repo with 35,000 files (Magento 1)

Just had this popup in Sierra.

Exciting times huh.

By adam.j.cooper at Oct. 11, 2016, 3:47 p.m. (reply...)

Also in El Capitan!

+1

Got it also in Yosemite...

By vladimir.knobel at Feb. 9, 2015, 4:56 p.m. (reply...)

+1

Also seeing this on Yosemite, twice in the last couple of weeks.

Still getting the bug in Yosemite. :(


Please note: Reports posted here will not necessarily be seen by Apple. All problems should be submitted at bugreport.apple.com before they are posted here. Please only post information for Radars that you have filed yourself, and please do not include Apple confidential information in your posts. Thank you!