3

I have a Java program which launches a separate subprocess represented by the Process class, and then attaches listeners which look at the stdout/stderr of the Process. In some cases, the Process will hang and stop being able to make progress, at which time the TimeLimiter will throw a TimeoutException, attempt to interrupt the underlying thread which is actually doing the readLine() call, and then kill the Process using kill -9 and close the stdout and stderr streams from the Process object. The last thing it tries to do is close the BufferedReader, but this call hangs forever. Sample code below:

private static final TimeLimiter timeLimiter = new SimpleTimeLimiter(); // has its own thread pool

public void readStdout(Process process) {
    BufferedReader reader = new BufferedReader(new InputStreamReader(process.getInputStream()));
    try {
        String line = null;
        while ((line = timeLimiter.callWithTimeout(reader::readLine, 5, TimeUnit.SECONDS, true)) != null) { // this will throw a TimeoutException when the process hangs
            System.out.println(line);
        }
    } finally {
        killProcess(process); // this does a "kill -9" on the process
        process.getInputStream().close(); // this works fine
        process.getErrorStream().close(); // this works fine
        reader.close(); // THIS HANGS FOREVER
    }
}

Why does the close() call hang forever, and what can I do about it?

Related question: Program freezes on bufferedreader close

UPDATE:

In case it wasn't clear, TimeLimiter is from the Guava libraries: https://github.com/google/guava/blob/master/guava/src/com/google/common/util/concurrent/SimpleTimeLimiter.java

Also, I've been asked for the code from the killProcess() method, so here it is (note this only works on Linux/Unix machines):

public void killProcess(Process process) {
    // get the process ID (pid)
    Field field = process.getClass().getDeclaredField("pid"); // assumes this is a java.lang.UNIXProcess
    field.setAccessible(true);
    int pid = (Integer)field.get(process);

    // populate the list of child processes
    List<Integer> processes = new ArrayList<>(Arrays.asList(pid));
    for (int i = 0; i < processes.size(); ++i) {
        Process findChildren = Runtime.getRuntime().exec(new String[] { "ps", "-o", "pid", "--no-headers", "--ppid", Integer.toString(processes.get(i)) });
        findChildren.waitFor(); // this will return a non-zero exit code when no child processes are found
        Scanner in = new Scanner(findChildren.getInputStream());
        while (in.hasNext()) {
            processes.add(in.nextInt());
        }
        in.close();
    }

    // kill all the processes, starting with the children, up to the main process
    for (int i = processes.size() - 1; i >= 0; --i) {
        Process killProcess = Runtime.getRuntime().exec(new String[] { "kill", "-9", Integer.toString(processes.get(i)) });
        killProcess.waitFor();
    }
}
Dasmowenator
  • 5,505
  • 5
  • 36
  • 50
  • How are you killing the process exactly? [Process#destroy()](http://hg.openjdk.java.net/jdk8/jdk8/jdk/file/jdk8-b132/src/solaris/classes/java/lang/UNIXProcess.java.linux#l295) and its sibling destroyForcibly seem to clean up the streams too. People have had more [success](https://stackoverflow.com/questions/36958447/java-stop-process-and-close-streams) with it in a similar situation. – Vasan Apr 13 '18 at 22:54
  • Well I tried to simplify this in the post, but if you want more details, the process we're running is actually ffmpeg, and ffmpeg spins off all sorts of subprocesses. When ffmpeg hangs, we originally just tried destroy() and destroyForcibly() as you said, but it turns out those methods didn't destroy the subprocesses, so we had to write a subroutine which uses "ps" to list PIDs and subprocesses, then goes through and does "kill -9" on every process and subprocess in the process tree. – Dasmowenator Apr 14 '18 at 00:05

3 Answers3

2

The underlying issue here is with multi-threading and synchronization locks. When you call timeLimiter.callWithTimeout it's creating another thread in a thread pool to actually do the readLine(). When the call times out, the main thread tries to call close(), but unfortunately the readLine() and close() methods in the BufferedReader use the same synchronization lock object, so since another thread already has the lock, this call will block until the other thread relinquishes it. But if the readLine() call never returns, then the close() call will hang forever. Here's a snip-it of the BufferedReader source code:

String readLine(boolean ignoreLF) throws IOException {
    StringBuffer s = null;
    int startChar;

    synchronized (lock) {
        ensureOpen();
        boolean omitLF = ignoreLF || skipLF;
        ...
        ...
        ...
    }
}

public void close() throws IOException {
    synchronized (lock) {
        if (in == null)
            return;
        try {
            in.close();
        } finally {
            in = null;
            cb = null;
        }
    }
}

Of course, the TimeLimiter will try to interrupt the thread which is doing the readLine(), so that thread should really exit and let the thread trying to call close() go through. The real bug here is that the thread interruption isn't being respected by BufferedReader. In fact, there is already a bug reported in the JDK tracker about this very thing, but it's marked as "won't fix" for some reason: https://bugs.openjdk.java.net/browse/JDK-4859836

Although, to be fair, it's not really BufferedReader's responsibility to honor the thread interrupt. BufferedReader is just a buffer class, all calls to its read() or readLine() methods just read data from the underlying input stream. In this case, the underlying class is an InputStreamReader, which if you look at its source code, creates a StreamDecoder under the hood to do all of its read operations. Really, the bug is with StreamDecoder -- it should honor thread interrupts, but it doesn't.

What to do about it? Well for better or for worse, there's no way to force an object to give up its thread lock. Since StreamDecoder is obviously not code that we own or can edit, there's not much we can do. My current solution was just to remove the part where we call close() on the BufferedReader, so now at least the program doesn't hang forever. But it's still a memory leak... that thread which is running readLine() in the TimeLimiter's thread pool will essentially run forever. Since this is all part of a long-running program which processes a lot of data over time, eventually that thread pool will fill up with junk threads and the JVM will crash...

If anyone has any other advice for how to work around this, please let me know.

Dasmowenator
  • 5,505
  • 5
  • 36
  • 50
0

If you kill the process, the stdout/stderr should dry out not long after (EOF and null from readLine eventually when OS pipes dry out).

At least, closing the streams should cause the concurrent readers/writers to fail. That works on sockets, so I expect it to work on files and processes...

So I see no point in calling the bufferedreader.close(), you have nothing to loose. BufferedReader is just memory that will be freed on GC. The underlying streams were already closed, and even then, the process is killed. One of those kill or close must eject the slave thread's readLine with null or some exception.

UPDATE:

The code below shows that killing the process will end the streams as expected:

package tests;

import java.io.BufferedReader;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.concurrent.TimeUnit;
import java.util.stream.Stream;

public class TestProcessStreamsCloseEOF {

    static void p(Object msg, Throwable... ta) {
        StringWriter sw = new StringWriter();
        PrintWriter pw = new PrintWriter(sw);
        pw.println(Thread.currentThread().getName()+"] "+msg);

        if(ta!=null && ta.length>0)
            Stream.of(ta).forEach(t -> t.printStackTrace(pw));
        pw.flush();
        System.out.print(sw.toString());
    }

    public static void main(String[] args) throws Exception {
        /*
        slowecho.bat:
        -----------
        @echo off
        echo line 1
        pause
        echo line 2
        */
        Process p = new ProcessBuilder("slowecho.bat").start();
        new Thread(() -> {dump(p.getInputStream());}, "dumpstdout").start();
        new Thread(() -> {dump(p.getErrorStream());}, "dumpstderr").start();

        p("sleep 5s");
        Thread.sleep(5000);

        p("destroy...");
        //p.destroy();
        p.destroyForcibly();

        p("waitfor 5s");
        p.waitFor(5, TimeUnit.SECONDS);

        p("sleep 5s");
        Thread.sleep(5000);

        p("end.");
    }

    static void dump(InputStream is) {
        try {
            BufferedReader br = new BufferedReader(new InputStreamReader(is, "ISO-8859-1"));
            String line;
            while((line=br.readLine()) !=null) {
                p(line);
            }
        } catch(Throwable t) {
            p(""+t, t);
        }
        p("end");
    }

}
user2023577
  • 1,752
  • 1
  • 12
  • 23
  • Yes, the stdout and stderr streams have been closed, but the BufferedReader never gets an EOF, it just hangs forever. And since it's being run in a separate thread, won't it be a memory leak? I assume the thread won't be garbage collected until the BufferedReader.readLine() returns... – Dasmowenator Apr 16 '18 at 18:44
  • how do you know the slave thread on readline has not returned? the while loop exited with an exception, but what's the slave thread code doing when readline fails? we don't see that SimpleTimeLimiter's code. I'm saying, we can't help you much without all the code. – user2023577 Apr 16 '18 at 22:43
  • Because if I call get() on the Future it never returns. If you look at my answer I posted - the issue is that StreamDecoder doesn't honor a thread interrupt while it's waiting for input during read(). The fact that my app hung when I tried to close the BufferedReader was a symptom of that since the read() and close() operations try to acquire the same synchronization lock. Whether or not I can close the reader or not isn't really my biggest concern since I already closed the underlying streams, but the fact that there's a thread that's stuck indefinitely in the read() method is a memory leak. – Dasmowenator Apr 17 '18 at 01:14
  • Again, can you provide full code? You mention kill -9. The Process class already has a destroy. Nevertheless, I can understand the need for certainty. I stopped trying to interrupt streams a long time ago because this is just a flag the code must check. Native read/writes are notoriously bad for interruption. But closing them never failed me, and I cannot assert what you claim without the full code. I'm sure oracle didn't fail to implement something as obvious as kicking out pending calls upon a closing stream. Maybe your kill -9 is not graceful enough. Anyway, show the code, please. – user2023577 Apr 17 '18 at 12:11
  • BTW, if you expect anyone to honor an interrupt, you will be disappointed a lot more often than pleased. 3rd party libs are especially BAD at it. And in IO, it's even worse, since the InterruptedIOException extends IOException, NOT InterruptedEception. Way too easy to catch by mistake and let retries kick in mistakenly. – user2023577 Apr 17 '18 at 12:20
  • @Dasmowenator I added sample code to prove the process streams get EOF'ed. I knew I wasn't crazy... LOL. (jdk8, win10). So, I suspect there is something in your code (that we don't see) that causes a retry of the readline or some other method using the lock. – user2023577 Apr 17 '18 at 14:04
  • In case it wasn't clear, TimeLimiter is from the Guava libraries: https://github.com/google/guava/blob/master/guava/src/com/google/common/util/concurrent/SimpleTimeLimiter.java – Dasmowenator Apr 17 '18 at 17:55
  • And about the killProcess() method? It would help future readers if you edited your question and completed your code. As it stands, it cannot reproduced. – user2023577 Apr 17 '18 at 22:15
  • Ok I updated it with the code from the killProcess() method. – Dasmowenator Apr 18 '18 at 19:02
  • Ok, so the only interrupt is from the guava future.cancel(true) upon timeout, which is not honored by a nitive fileinputstream.read() of the process stdout. Up to there, this is no surprise. The question is therefore why the process's stdout fileinputstream doesn't go EOF upon your kill -9. So I would suggest you try a normal kill (no -9) to see how the OS+JVM will play it out. You have this odd children tree of process to deal with, I understand, but it doesn't seem to require a nuke like kill -9. I could be a jvm bug in the process stream implementation. – user2023577 Apr 18 '18 at 19:37
0

I would rather prefer to handle resources gracefully like below

import java.io.BufferedReader;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.stream.Stream;

public class Test {

    static AtomicBoolean interruptLoggingThread = new AtomicBoolean(false);

    static void print(Object msg, Throwable... expArr) {
        StringWriter sw = new StringWriter();
        PrintWriter pw = new PrintWriter(sw);
        pw.println(Thread.currentThread().getName() + "] " + msg);

        if (expArr != null && expArr.length > 0) {
            Stream.of(expArr).forEach(exp -> exp.printStackTrace(pw));
        }
        pw.flush();
        System.out.print(sw.toString());
    }

    public static void main(String[] args) throws Exception {
        Process p = new ProcessBuilder("slowecho.bat").start();
        new Thread(() -> {
            dump(p.getInputStream());
        }, "dumpstdout").start();
        new Thread(() -> {
            dump(p.getErrorStream());
        }, "dumpstderr").start();

        try {
            p.waitFor(10000, TimeUnit.SECONDS); // Wait process to terminate within 10 Seconds
            interruptLoggingThread.set(true);
            p.destroyForcibly(); // To ensure process got terminated forcibly (if not gracefully terminated within 10 seconds)
        } catch (Exception e) {
        }
        try {
            p.getInputStream().close(); // Ensure to close standard output stream
        } catch (Exception e) {
        }
        try {
            p.getErrorStream().close(); // Ensure to close standard error stream
        } catch (Exception e) {
        }
    }

    static void dump(InputStream is) {
        try {
            BufferedReader br = new BufferedReader(new InputStreamReader(is, "ISO-8859-1"));
            String line;
            while (!interruptLoggingThread.get()) {
                if (br.ready()) { // ready() is non-blocking
                    line = br.readLine();
                    // ready() check ensures, readLine() will not be blocked for input
                    if (line != null) {
                        print(line);
                    }
                } else {
                    Thread.sleep(1000l);
                }
            }
        } catch (Throwable t) {
            print("" + t, t);
        }
        print("end");
    }
}
Anil Agrawal
  • 2,748
  • 1
  • 24
  • 31