<div dir="ltr">Hi guys, <div><br></div><div>There is a bug happening in OSSubprocess since quite some time which we were never able to fix. What happens is that at certain point (after having used OSSubprocess for a while), a simple command like the following would "hang" Pharo:</div><div><br></div><div><span style="font-size:12.8px">OSSUnixSubprocess new</span><br style="font-size:12.8px"><span style="font-size:12.8px">    command: 'ls';</span><br style="font-size:12.8px"><span style="font-size:12.8px">    arguments: #();</span><br style="font-size:12.8px"><span style="font-size:12.8px">    redirectStdout;</span><br style="font-size:12.8px"><span style="font-size:12.8px">    runAndWaitOnExitDo: [ :process :outString  | outString ]</span><span class="gmail-im" style="font-size:12.8px"><br></span><div><br></div><div>Once the image does that, it keeps doing it in a 80% of the cases (so it is easy enough to debug). </div><div><br></div><div>Guille Polito kept one of these images if someone can give us a hand. He also proposed the great idea of using `strace` to see what was going on. He  (together with Pable Tesone) suspected that the heartbeat could be interrupting the `clone()` function which is (I think) called internally by the 'posix_spawn()' which is the one used by OSSubprocess.</div><div><br></div><div>When these images are "hung" they found at a infinitive loop like this:</div><div><br></div><div><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 593498}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 600126}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 606282}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 612528}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 618689}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 624922}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 631145}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 637241}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 643578}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] gettimeofday({1482152630, 649974}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] sigreturn() (mask [])       = 120</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|</span><wbr style="font-size:12.8px"><span style="font-size:12.8px">CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7578768) = ? ERESTARTNOINTR (To be restarted)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 17477] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"></div><div><span style="font-size:12.8px"><br></span></div><div><span style="font-size:12.8px">As you can see, there is a SIGALARM involved. It also looks like the `gettimeofday` is used by the heartbeat ?  Could it be that someone the heartbeat is interrupting the `clone()` ?</span></div><div><span style="font-size:12.8px"><br></span></div><div><span style="font-size:12.8px">Guille also showed me the `strace` output with a regular / working image:</span></div><div><span style="font-size:12.8px"><br></span></div><div><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] gettimeofday({1482152829, 481014}, NULL) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] sigreturn() (mask [])       = -1 EINTR (Interrupted system call)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] getitimer(ITIMER_REAL, {it_interval={0, 2000}, it_value={0, 1917}}) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] recvmsg(3, 0xff7b0734, 0)   = -1 EAGAIN (Resource temporarily unavailable)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] select(4, [3], [], [3], {0, 1000}) = 0 (Timeout)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] getitimer(ITIMER_REAL, {it_interval={0, 2000}, it_value={0, 797}}) = 0</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] recvmsg(3, 0xff7b0734, 0)   = -1 EAGAIN (Resource temporarily unavailable)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] select(4, [3], [], [3], {0, 1000}) = ? ERESTARTNOHAND (To be restarted if no handler)</span><br style="font-size:12.8px"><span style="font-size:12.8px">[pid 18647] --- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL} ---</span><span class="gmail-im" style="font-size:12.8px"><br></span></div><div><span style="font-size:12.8px"><br></span></div><div><span style="font-size:12.8px"><br></span></div><div><span style="font-size:12.8px">Does anyone have any hint here?  </span></div><div><span style="font-size:12.8px"><br></span></div><div><span style="font-size:12.8px">Thanks in advance, </span></div><div><br></div><div><br></div>-- <br><div class="gmail_signature">Mariano<br><a href="http://marianopeck.wordpress.com" target="_blank">http://marianopeck.wordpress.com</a><br></div>
</div></div>