[squeak-dev] Unix OSProcess error

Hi -

This morning I was greeted with a sequence of "Error: cannot create OS
pipe" from one of our servers (running RHEL 5.3) and I am trying to
understand what might be causing this. The call stack is included below;
it appears that #makePipeHandles returns nil and I am not sure what
might be causing this. Is there a possibility that there is some limit
on the number of handles that we might be exceeding? Some missing cleanup?

Thanks for any help,
   - Andreas

ExternalPipe>>makePipe
        Receiver: an ExternalPipe
        Arguments and temporary variables:
                handleArray: nil
        Receiver's instance variables:
                writer: nil
                reader: nil
                blocking: nil

ExternalPipe>>initialize
        Receiver: an ExternalPipe
        Arguments and temporary variables:

        Receiver's instance variables:
                writer: nil
                reader: nil
                blocking: nil

ExternalPipe class>>blockingPipe
        Receiver: ExternalPipe
        Arguments and temporary variables:

        Receiver's instance variables:
                superclass: Stream
                methodDict: a MethodDictionary(#atEnd->a CompiledMethod(58:
ExternalPipe>>atEnd...etc...
                format: 136
                instanceVariables: #('writer' 'reader' 'blocking')
                organization: ('testing' atEnd atEndOfFile closed isPipe)
('accessing' blocking...etc...
                subclasses: #(OSPipe)
                name: #ExternalPipe
                classPool: nil
                sharedPools: nil
                environment: a SystemDictionary(lots of globals)
                category: #'OSProcess-Base'

PipeableOSProcess>>createInputPipe
        Receiver: a PipeableOSProcess on nil
        Arguments and temporary variables:

        Receiver's instance variables:
                dependents: nil
                pipeToInput: nil
                pipeFromOutput: nil
                errorPipelineStream: nil
                pipeFromError: nil
                processProxy: nil
                keepInitialStdOutOpen: nil
                keepInitialStdErrOpen: nil
                accessProtect: a Semaphore()
                completion: a Semaphore()

--------------------------------------------------------------------
PipeableOSProcess
class>>new:arguments:environment:descriptors:workingDir:errorPipelineStream:
PipeableOSProcess
class>>forkAndExec:arguments:environment:descriptors:workingDir:errorPipelineStream:
PipeableOSProcess
class>>command:environment:workingDir:input:output:error:errorPipelineStream:shellSyntax:
PipeableOSProcess
class>>command:environment:workingDir:input:output:error:errorPipelineStream:

On Thu, Aug 06, 2009 at 11:29:25AM -0700, Andreas Raab wrote:
Most likely you are hitting the limit for open file handles (a per-process
limit on unix, probably set to 1024 unless you have changed it). Find the
pid of the Squeak VM process in question ('pgrep -l squeak' from unix command
line, or 'OSProcess thisOSProcess pid' in the image). Then, assuming pid is
12345, look at the information in the proc file system, "ls -l /proc/12345/fd/*".
This will probably show you about a thousand open file handles on pipes.

Assuming that is the case, the problem is failure to cleanly close all pipe
handles. Not all of the examples that you find in OSProcess will necessarily
do this (and it's usually best to go ahead and load CommandShell to get
access to some higher-level tools). In particular some of the examples will
e.g. run an external command but leave the output pipes open on the assumption
that you will want to want to read them. In cases like that, the pipes need
to be explicitly closed to avoid a file handle leak.

Note also that the normal finalization of FileStreams is disabled for streams
on OS pipes (due to performance issues with weak registries, which gets
disasterously bad if you do a lot of pipe creation). That means that pipe
handles that you do not explicitly close will linger forever in the unix
process.

The unit tests for CommandShell will include lots of examples of running
command pipelines and testing to ensure that all open files have been closed.
You may want to borrow some ideas from that.

If you can send me an example of something that you are doing, I'll try to
suggest something more specific to address the problem. I'm away from Squeak
at the moment, so it may take me a while to respond.

Dave

David T. Lewis wrote:
> If you can send me an example of something that you are doing, I'll try to
> suggest something more specific to address the problem. I'm away from Squeak
> at the moment, so it may take me a while to respond.

We're doing stuff along the lines of:

"fire off the external command"
cmd := PipeableOSProcess command: '/home/qwaq/server/script.sh'
        environment: nil
        workingDir: nil
        input: nil
        output: nil
        error: nil
        errorPipelineStream: nil.

"wait for completion"
start := Time millisecondClockValue.
[cmd isComplete not and:[(Time millisecondsSince: start) < deadline]]
        whileTrue:[(Delay forMilliseconds: 100) wait].
cmd isComplete ifFalse:[^self error: 'timeout'].

descriptors := cmd outputAndError.
"... processing of output and error omitted ..."

And that's it. Is there anything that we need to clean up here?

Thanks,
   - Andreas

On Thu, Aug 06, 2009 at 01:08:35PM -0700, Andreas Raab wrote:
Probably yes. From memory I think that 'cmd closePipes' will do what you
need. But I'm sure there are cleaner ways to do this, so I'll give you
a better answer later on when I get home a few hours from now. I guess
it's time I started carrying one of Bert's Squeak-on-a-stick solutions
on my keychain ;)

Dave

David T. Lewis wrote:
> Probably yes. From memory I think that 'cmd closePipes' will do what you
> need. But I'm sure there are cleaner ways to do this, so I'll give you
> a better answer later on when I get home a few hours from now. I guess
> it's time I started carrying one of Bert's Squeak-on-a-stick solutions
> on my keychain ;)

A quick test seems to indicate that no specific cleanup is required
after the command - I didn't see any extra open handles after running it
several times. However, there was an odd error earlier on the server in
question which I had ignored but might turn out related. The error was
"unsupported primitive, plugin may be out of date" (stack trace below)
and I am wondering whether that might have killed the grimReaperProcess
and led to the accumulation of the handles (no clue what might actually
cause that error; the plugin is up-to-date).

In any case, thanks for the /proc/pid/fd pointer - this is actually
extremely useful information that I didn't know existed.

Cheers,
   - Andreas

UnixOSProcessAccessor(Object)>>error:
        Receiver: a UnixOSProcessAccessor on pid 7280
        Arguments and temporary variables:
                aString: 'unsupported primitive, plugin may be out of date'
        Receiver's instance variables:
                dependents: #(a UnixProcess with pid 7280)
                sessionIdentifier: a ByteArray(77 228 121 74)
                canObtainSessionIdentifierFromPlugin: true
                grimReaper: a Process in [] in Semaphore>>critical:
                sigChldSemaphore: a Semaphore()

UnixOSProcessAccessor>>isAtEndOfFile:
        Receiver: a UnixOSProcessAccessor on pid 7280
        Arguments and temporary variables:
                anIOHandle: nil
                atEof: nil
        Receiver's instance variables:
                dependents: #(a UnixProcess with pid 7280)
                sessionIdentifier: a ByteArray(77 228 121 74)
                canObtainSessionIdentifierFromPlugin: true
                grimReaper: a Process in [] in Semaphore>>critical:
                sigChldSemaphore: a Semaphore()

AttachableFileStream(StandardFileStream)>>atEndOfFile
        Receiver: AttachableFileStream: 'pipeReader'
        Arguments and temporary variables:

        Receiver's instance variables:


AttachableFileStream>>upToEndOfFile
        Receiver: AttachableFileStream: 'pipeReader'
        Arguments and temporary variables:
                newStream: a WriteStream ''
                buffer:
'€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€€...etc...
        Receiver's instance variables:


ExternalPipe>>upToEndOfFile
        Receiver: an ExternalPipe
        Arguments and temporary variables:

        Receiver's instance variables:
                writer: AttachableFileStream: 'pipeWriter'
                reader: AttachableFileStream: 'pipeReader'
                blocking: false


--- The full stack ---
UnixOSProcessAccessor(Object)>>error:
UnixOSProcessAccessor>>isAtEndOfFile:
AttachableFileStream(StandardFileStream)>>atEndOfFile
AttachableFileStream>>upToEndOfFile
  - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
ExternalPipe>>upToEndOfFile
[] in PipeableOSProcess>>update:
ExternalPipe(Object)>>ifNotNilDo:
PipeableOSProcess>>update:
[] in ExternalUnixOSProcess(Object)>>changed:
DependentsArray>>do:
ExternalUnixOSProcess(Object)>>changed:
ExternalUnixOSProcess(ExternalOSProcess)>>runState:
ExternalUnixOSProcess(ExternalOSProcess)>>complete
ExternalUnixOSProcess>>update:
[] in UnixProcess(ThisOSProcess)>>updateActiveChildren
[] in Dictionary>>do:
Dictionary(Set)>>do:
Dictionary>>do:
UnixProcess(ThisOSProcess)>>updateActiveChildren
UnixProcess>>update:
[] in UnixOSProcessAccessor(Object)>>changed:
DependentsArray>>do:
UnixOSProcessAccessor(Object)>>changed:
[] in [] in UnixOSProcessAccessor>>grimReaperProcess
BlockClosure>>repeat
[] in UnixOSProcessAccessor>>grimReaperProcess
[] in BlockClosure>>newProcess

On Thu, Aug 06, 2009 at 02:36:35PM -0700, Andreas Raab wrote:
Check that file handle count once again. I expect that you will be seeing
one extra file handle left open each time you run the external shell script
(but you are running a different version of OSProcess from my latest, so
I'm not 100% sure).  Adding the "cmd closePipes" will do the necessary
cleanup; I just checked this on my system at home. In other words, do your
wait loop like this:

  [cmd isComplete not and:[(Time millisecondsSince: start) < deadline]]
        whileTrue:[(Delay forMilliseconds: 100) wait].
  cmd closePipes.
  cmd isComplete ifFalse:[^self error: 'timeout'].


> However, there was an odd error earlier on the server in
> question which I had ignored but might turn out related. The error was
> "unsupported primitive, plugin may be out of date" (stack trace below)
> and I am wondering whether that might have killed the grimReaperProcess
> and led to the accumulation of the handles (no clue what might actually
> cause that error; the plugin is up-to-date).

Oh-oh, I'm not so sure about that. The "unsupported primitive, plugin may
be out of date" message comes from UnixOSProcessAccessor>>isAtEndOfFile in
an older version of OSProcess, which means that your OSProcess and CommandShell
packages are a bit out of date. Latest versions are:

  OSProcess versionString ==> '4.3.8'
  CommandShell versionString ==> '4.4.1'

But that's probably not the problem. I suspect that the error message is
correct, and your OSPP plugin actually *is* out of date. You can query
the running plugin for its version string, which on an up to date OSPP
would be this:

  OSProcess accessor osppModuleVersionString ==> '4.3.3'

If you have something very much older, it may be causing problems.

In particular, make sure that it's not version 4.2.6, which is the very
out of date version (December 2007) that seems to have been included in
Ian's most recent build. This is the down side of the "maintain everything
as external modules" theory I guess. I had suggested to Ian that he do an
update "with the latest VMMaker" to get the closure support in place, but
I didn't say anything about updating other externally maintained plugins.
I guess that means that I need to educate myself about MonticelloConfigurations
one of these days.

In summary:
 - Add "cmd closePipes" to make sure that pipe handles are getting cleaned up.
   I'm fairly sure that this will correct the file handle leak.
 - Check "OSProcess accessor osppModuleVersionString" to make sure you
   really are running an up to date version.
 - (Optional) Load the latest OSProcess and CommandShell from SqueakSource.

Dave