Foreman does not terminate child processes

[Svalorzen]

This is probably some kind of duplicate of #94, but I tried looking around for this and I could not find anything. The problem happened with foreman cloned and installed just now, with Ruby 2.3.0.

My Procfile is this:

# Foreman proc file
socatM0: socat -v -x PTY,link=/tmp/ttyM0,raw,echo=0 PTY,link=/tmp/ttyMXUSB0,raw,echo=0,nonblock >/dev/null 2>&1
socatM1: socat -v -x PTY,link=/tmp/ttyM1,raw,echo=0 PTY,link=/tmp/ttyMXUSB1,raw,echo=0,nonblock >/dev/null 2>&1
cus:  src/cus/Debug/cus     -c "config/obcu/config_cus.ini"  2>/dev/null
tcms: src/tcms/Debug/tcms   -c "config/obcu/config_tcms.ini" 2>/dev/null
tag1: src/tag/Debug/tag     -c "config/obcu/config_tag1.ini" 2>/dev/null
tag2: src/tag/Debug/tag     -c "config/obcu/config_tag2.ini" 2>/dev/null
avl:  src/avl/Debug/avl     -c "config/obcu/config_avl.ini"  2>/dev/null
cab:  src/cab/Debug/cab     -c "config/obcu/config_cab.ini"  2>/dev/null
pis:  src/pis/Debug/pis     -c "config/obcu/config_pis.ini"  2>/dev/null
dia:  src/dia/Debug/dia     -c "config/obcu/config_dia.ini"  2>/dev/null
i18n: src/i18n/Debug/i18n   -c "config/obcu/config_i18n.ini" 2>/dev/null
hmi:  src/hmi/Debug/hmi     -c "config/dci1/config_hmi.ini"  2>/dev/null

After sending Ctrl-C to foreman, it prints that all processes have been terminated:

16:18:24 socatM0.1 | terminated by SIGTERM
16:18:24 socatM1.1 | terminated by SIGTERM
16:18:24 cus.1     | terminated by SIGTERM
16:18:24 tcms.1    | terminated by SIGTERM
16:18:24 tag1.1    | terminated by SIGTERM
16:18:24 tag2.1    | terminated by SIGTERM
16:18:24 avl.1     | terminated by SIGTERM
16:18:24 cab.1     | terminated by SIGTERM
16:18:24 pis.1     | terminated by SIGTERM
16:18:24 dia.1     | terminated by SIGTERM
16:18:25 i18n.1    | terminated by SIGTERM

But they remain in processes..

[Svalorzen]

With the following edited Procfile the problem does not seem to happen, but I have no idea why, aside from the fact tha I tried to eliminate as many characters referenced in #94 as possible:

# Foreman proc file
socatM0: socat -v -x PTY,link=/tmp/ttyM0,raw,echo=0 PTY,link=/tmp/ttyMXUSB0,raw,echo=0,nonblock
socatM1: socat -v -x PTY,link=/tmp/ttyM1,raw,echo=0 PTY,link=/tmp/ttyMXUSB1,raw,echo=0,nonblock
cus:  src/cus/Debug/cus     -c config/obcu/config_cus.ini
tcms: src/tcms/Debug/tcms   -c config/obcu/config_tcms.ini
tag1: src/tag/Debug/tag     -c config/obcu/config_tag1.ini
tag2: src/tag/Debug/tag     -c config/obcu/config_tag2.ini
avl:  src/avl/Debug/avl     -c config/obcu/config_avl.ini
cab:  src/cab/Debug/cab     -c config/obcu/config_cab.ini
pis:  src/pis/Debug/pis     -c config/obcu/config_pis.ini
dia:  src/dia/Debug/dia     -c config/obcu/config_dia.ini
i18n: src/i18n/Debug/i18n   -c config/obcu/config_i18n.ini
hmi:  src/hmi/Debug/hmi     -c config/dci1/config_hmi.ini

[ddollar]

Would it be possible to put together a small Procfile that demonstrates the problem?

[Svalorzen]

I'm trying to make it smaller, although I'm going randomly as I have no idea what the problem might be. One thing I have noticed: if foreman kills processes and prints this:

10:44:11 socatM0.1 | terminated by SIGINT
10:44:11 socatM1.1 | terminated by SIGINT
10:44:12 cus.1     | terminated by SIGINT
10:44:12 tcms.1    | terminated by SIGINT
10:44:12 tag1.1    | terminated by SIGINT
10:44:12 tag2.1    | terminated by SIGINT
10:44:12 avl.1     | terminated by SIGINT
10:44:12 cab.1     | terminated by SIGINT
10:44:12 pis.1     | terminated by SIGINT
10:44:12 dia.1     | terminated by SIGINT
10:44:12 i18n.1    | terminated by SIGINT

Then it means that it really killed the processes. When it prints that it terminates them by SIGTERM then it fails. I'll keep doing experiments trying to make a Procfile which reproduces the problem in the meantime, but maybe this can be a hint to something?

[Svalorzen]

By using watch, I have noticed that in those cases the process that foreman actually starts is this:

svalorz+ 31193  0.0  0.0   4508   756 pts/2    S+   11:03   0:00 sh -c src/cus/Debug/cus     -c "config/obcu/config_cus.ini"  2>/dev/null

So what happens is that it kills sh but not the underlying process, which remains up (and with a different PID)

svalorz+ 31195  0.0  0.1 482488 13188 pts/2    Sl+  11:03   0:00 src/cus/Debug/cus -c config/obcu/config_cus.ini

I'm trying to reproduce it with smaller programs so that you can reproduce it but I can't seem to. However I have reduced the procfile, this happens with:

# Foreman proc file
cus:  src/cus/Debug/cus     -c "config/obcu/config_cus.ini"  2>/dev/null

It seems that with SIGINT the underlying sh is able to manage killing the child process, while with SIGTERM it does not happen.

[Svalorzen]

Reproduced. Make two programs:

// broken.cpp
int main() {
    return 255;
}

// loop.cpp
int main() {
    while (true) {}
    return 0;
}

Compile them.

g++ -o broken broken.cpp
g++ -o loop loop.cpp

Make Procfile:

# Foreman proc file
test1:  ./loop "1000"
test2:  ./broken "1000"

Launch foreman:

$ foreman start
11:14:20 test1.1 | started with pid 9186
11:14:20 test2.1 | started with pid 9187
11:14:20 test2.1 | exited with code 255
11:14:20 system  | sending SIGTERM to all processes
11:14:20 test1.1 | terminated by SIGTERM

Process remains:

$ ps aux | grep loop
svalorz+  9188  100  0.0   4224   724 pts/12   R    11:14   0:32 ./loop 1000
svalorz+  9644  0.0  0.0  14232   964 pts/12   S+   11:14   0:00 grep --color=auto loop

[Svalorzen]

(Note that the arguments are not needed, without them it works fine, but I guess you invoke "sh" only when there are special characters?)

[Svalorzen]

So now I did a new search and I realized that there are multiple closed issues ( #365, #428, #357 and others..) about this exact problem, and that in theory foreman is supposed to forward SIGTERM to child processes. No idea why it is not doing that on my system though..

[bbozo]

Same (?) thing here, when I exit foreman with Ctrl+C, all child processes get killed off nicely, when foreman exits because one of the child apps exploded, then it writes it stopped the children, but it doesn't.

I'm using foreman 0.82.0 with ruby 2.2.4p230

[ddollar]

I believe this should not be happening in the latest foreman. Please comment here if you're still seeing this.