Cryptic log message
björn
I have noticed the appearance of log messages on the Console that I do
not understand. Can anybody tell me what this means?
8/14/08 1:54:42 PM com.apple.launchd[65]
([0x0-0x2d02d].org.vim.MacVim[22668]) Stray process with PGID equal to
this dead job: PID 22683 PPID 1 Vim
I noticed it as I was testing snapshot 28 and it also happens with
latest so its not something recent even though I've never spotted this
message before.
Thanks,
Björn
Ben Schmidt
I'm guessing this has to do with zombie processes, which I've noticed a
few of with MacVim recently, too. The gist of it is that when a process
exits, its exit status is kept so that the parent process can check it.
During this time that a process is dead but its exit status is kept, it
is in the process table as a zombie, and the ps(1) command will show a Z
for it (that's where I noticed it). The way to fix this is either to
signal to the OS that we're not interested our children's exit statuses
by ignoring the SIGCHLD signal, or to check their statuses when they
exit by catching and handling that signal (using a wait(2) call to get
the status, probably, and for example showing a dialog if it is
non-zero, i.e. abnormal termination--I guess you'd have to queue an
event in a safe asynchronous way to do this, and then let MacVim handle
it in its run loop, as the signal could arrive at any time).
Thing is...the default is already to ignore SIGCHLD, so this seems odd.
Maybe when MacVim is started via Vim -g rather than a double-click it
inherits some different signal setup that Vim does, so that needs to be
reversed. Does the log message occur in any particular scenario that you
can determine, e.g. if you start MacVim via Vim rather than a double
click?
The way to ignore SIGCHLD is
#include <signal.h>
signal(SIGCHLD, SIG_IGN);
It is possibly more complicated than this: e.g. the processes we are
seeing messages for may be processes that Vim starts, not MacVim, and
I'm not sure when the messages would appear: perhaps when a parent exits
without having checked the child exit status. It also seems tied up with
LaunchServices, so perhaps it has nothing to do with SIGCHLD but there
is a more LaunchServices-specific way to signal we are not interested in
the exit status or something.
I think those are the areas to investigate though. And although it would
be nice to get rid of the messages, I don't think it's a serious
problem.
Ben.
Nico Weber
>> do
>> not understand. Can anybody tell me what this means?
>>
>> 8/14/08 1:54:42 PM com.apple.launchd[65]
>> ([0x0-0x2d02d].org.vim.MacVim[22668]) Stray process with PGID equal
>> to
>> this dead job: PID 22683 PPID 1 Vim
>>
>
> noticed a
> few of with MacVim recently, too.
>
> odd.
> Maybe when MacVim is started via Vim -g rather than a double-click it
> inherits some different signal setup that Vim does, so that needs to
> be
> reversed.
Could it be that fork()ing resets the SIGCHLD handler? Alternatively,
directly after forking, we call setsid() and exec(). Do we need to
call `signal(SIGCHLD, SIG_IGN)` after forking or setsidding?
Nico
Ben Schmidt
>>> I have noticed the appearance of log messages on the Console that I
>>> do
>>> not understand. Can anybody tell me what this means?
>>>
>>> 8/14/08 1:54:42 PM com.apple.launchd[65]
>>> ([0x0-0x2d02d].org.vim.MacVim[22668]) Stray process with PGID equal
>>> to
>>> this dead job: PID 22683 PPID 1 Vim
>>>
>> I'm guessing this has to do with zombie processes, which I've
>> noticed a
>> few of with MacVim recently, too.
>>
>> Thing is...the default is already to ignore SIGCHLD, so this seems
>> odd.
>> Maybe when MacVim is started via Vim -g rather than a double-click it
>> inherits some different signal setup that Vim does, so that needs to
>> be
>> reversed.
>
> Could it be that fork()ing resets the SIGCHLD handler?
Shouldn't. But if it does, it should be resetting it to what we want
anyway.
> Alternatively,
> directly after forking, we call setsid() and exec(). Do we need to
> call `signal(SIGCHLD, SIG_IGN)` after forking or setsidding?
In theory it is the parent process that matters, not the child (i.e.
MacVim before forking). That would be in line with my seeing zombie Vim
processes, too.
But if it is the more complicated case of a grandchild (i.e. a process
started by Vim) *and* Vim doesn't do anything of its own with this
signal (which I think is unlikely--Vim needs to deal with that signal in
order to run commands while displaying their output in the GUI and get
the exit status), then that might have a bearing.
Still, if the ppid is 1, the dead process is a child of init (or
whatever it's called on OS X these days--it's changed, but it does the
same kind of things...), which suggests it started via LaunchServices
(the non login-shell case, perhaps?) or its parent has exited (MacVim
itself perhaps). Given that another process is claimed to have that same
pgid, it is in the session of the dead process, which suggests it is a
process started by Vim (due to the setsid only Vim and its children have
that pgid). There may be another explanation, though. Do you know a way
to reproduce it, Björn? Maybe this particular message only happens when
MacVim crashes. And/or maybe these are two unrelated or only slightly
related issues...
Ben.
Nico Weber
> MacVim before forking). That would be in line with my seeing zombie
> Vim
> processes, too.
Just to be clear: MacVim itself doesn't fork, only the vim process
(and only if it is started form the terminal, e.g. after `mvim
<something>`). It does this to become independent of the Terminal you
launch it from (so that it doesn't close when you close that terminal).
Nico
björn
I've (only) seen those messages when running from Finder so it can't
have anything to do with forking (since the Vim processes don't fork
in this case).
Björn
Ben Schmidt
>> In theory it is the parent process that matters, not the child (i.e.
>> MacVim before forking). That would be in line with my seeing zombie
>> Vim processes, too.
>
> Just to be clear: MacVim itself doesn't fork,
Of course it does. It does so directly when using the login shell
option, and I suspect even when not doing that, the Cocoa API used is
implemented as a fork. (Maybe not, though, if that API works by doing
some kind of IPC with init or launchdaemon or whatever the darn thing is
called now. But I still suspect a fork, or at the very least, the
setting of the ppid and pgid to essentially simulate a fork.)
> only the vim process (and only if it is started from the terminal,
> e.g. after `mvim <something>`). It does this to become independent of
> the Terminal you launch it from (so that it doesn't close when you
> close that terminal).
Forking isn't necessary for that; just doing a setsid would accomplish
it (and/or ignoring SIGHUP probably). It wouldn't return control to the
user in the terminal, though, which is probably another desired
behaviour.
Ben.
björn
>
> that pgid). There may be another explanation, though. Do you know a way
> to reproduce it, Björn? Maybe this particular message only happens when
> MacVim crashes. And/or maybe these are two unrelated or only slightly
> related issues...
When it did happen all I had to do to reproduce it was to start MacVim
and then quit it again (with no timing constraints). Ok, its fully
reproducible by simply starting and quitting over and over again,
sometimes Console is a bit slow to actually log the message so it only
appears when I start MacVim again.
I figured out the cause though and why I've only recently seen this
log: just the other day I enabled the "use login shell" pref. After
disabling this pref the messages no longer appear!
Björn
Ben Schmidt
OK. Try the signal() call we've been discussing before the fork() call
in executInLoginShell; see if that helps. If it does, at least we know
what the problem is and can decide whether to leave it at that or
implement something nicer, like a handler that displays a dialog if the
Vim process dies improperly. (Of course, implementing a nice handler is
potentially a good idea even if this is not the cause of the messages.)
I'm still not convinced we've found the exact cause though. Another
thing that can be tried is inserting a setsid() call (just like that--no
arguments; no error check) in the child process just prior to the exec;
that might be a good idea anyway.
Does MacVim always die after its Vims or can MacVim die while Vims are
still shutting down? (Do you know if any important finalisations are
done in Vim potentially after MacVim dies?) Could be that an illogical
shutdown order causes some problems and makes a stronger case for adding
the setsid call. I would have thought these would be timing-related,
though, and since your errors don't seem to be, it suggests this isn't
it.
Ben.
Ben Schmidt
And for the record, I don't see the messages. Don't know why; could be a
Tiger vs. Leopard thing, I suppose. And it goes without saying I have
the login shell option turned on.
Smiles,
Ben.
björn
>
> Ben Schmidt wrote:
>>> 2008/8/14 Ben Schmidt <mail_ben...@yahoo.com.au>:
>>>> that pgid). There may be another explanation, though. Do you know a way
>>>> to reproduce it, Björn? Maybe this particular message only happens when
>>>> MacVim crashes. And/or maybe these are two unrelated or only slightly
>>>> related issues...
>>> When it did happen all I had to do to reproduce it was to start MacVim
>>> and then quit it again (with no timing constraints). Ok, its fully
>>> reproducible by simply starting and quitting over and over again,
>>> sometimes Console is a bit slow to actually log the message so it only
>>> appears when I start MacVim again.
>>>
>>> I figured out the cause though and why I've only recently seen this
>>> log: just the other day I enabled the "use login shell" pref. After
>>> disabling this pref the messages no longer appear!
>>
> OK. Try the signal() call we've been discussing before the fork() call
> in executInLoginShell; see if that helps. If it does, at least we know
> what the problem is and can decide whether to leave it at that or
> implement something nicer, like a handler that displays a dialog if the
> Vim process dies improperly. (Of course, implementing a nice handler is
> potentially a good idea even if this is not the cause of the messages.)
> I'm still not convinced we've found the exact cause though. Another
> thing that can be tried is inserting a setsid() call (just like that--no
> arguments; no error check) in the child process just prior to the exec;
> that might be a good idea anyway.
Ugh. Now I cannot reproduce it any longer either so I can't confirm
whether this helps or not. If I manage to reproduce it I'll try
again. I made some change to the source code since I could reproduce
this, but even after reverting to an older version I cannot reproduce
the problem.
> Does MacVim always die after its Vims or can MacVim die while Vims are
> still shutting down? (Do you know if any important finalisations are
> done in Vim potentially after MacVim dies?) Could be that an illogical
> shutdown order causes some problems and makes a stronger case for adding
> the setsid call. I would have thought these would be timing-related,
> though, and since your errors don't seem to be, it suggests this isn't
> it.
MacVim may or may not die before its Vim processes. Actually, I just
made some changes to get rid of those annoying "dropping DO message
..." logs and now it is more likely that the Vim processes die before
MacVim because they usleep() for 300 ms before they really die.
However, if MacVim dies before its Vim processes they are not likely
to be doing anything but waiting around in that usleep() call since
MacVim also usleep()s a bit after telling the Vim processes to exit.
So nothing exciting should be going on then.
> And for the record, I don't see the messages. Don't know why; could be a
> Tiger vs. Leopard thing, I suppose. And it goes without saying I have
> the login shell option turned on.
I'll run with the login shell option on some more and see if these
messages pop back up.
Björn
björn
>
> MacVim may or may not die before its Vim processes. Actually, I just
> made some changes to get rid of those annoying "dropping DO message
> ..." logs and now it is more likely that the Vim processes die before
> MacVim because they usleep() for 300 ms before they really die.
Sorry, that should have read: "...it is more likely that the Vim
processes die AFTER MacVim ...".
Björn
björn
ignoring SIGCHLD (yes, it took me an unreasonably long time to fix
this) so hopefully the issue with zombies has been fixed now, but let
me know if it is still there.
Thanks,
Björn