Guava SimpleTimeLimiter не блокирует время ожидания BufferedReader.readLine из Process.getInputStream

Question

Выпуск

Я пытаюсь установить таймаут вокруг BufferedReader.readLine() звонка. BufferedReader создается из java.lang.Process.getInputStream(). Самая многообещающая вещь, которую я нашел до сих пор, это Как установить время ожидания для BufferedReader и PrintWriter в Java 1.4? Если посмотреть на SimpleTimeLimiter в Guava, то выясняется, что они, похоже, решают эту проблему так же, как и я Я сделал это сам: с помощью Java 7 Executors / Callables / Futures. Это, однако, не работает, так как время ожидания просто не происходит в моей среде Unix. По крайней мере, не в допустимых пределах, вероятно, никогда.

Код

@Override
@Transactional
public Process call()
{
    java.lang.Process systemProcess = null;
    try
    {
        ProcessCallable.LOGGER.debug("executing command: {} ||| timeout: {} {}", this.process.getCommand(), this.getTimeout(), this.getTimeoutUnit());
        final String[] args = CommandLineUtils.translateCommandline(this.process.getCommand());
        final ProcessBuilder processBuilder = new ProcessBuilder(args);
        processBuilder.redirectErrorStream(true);
        systemProcess = processBuilder.start();
        final int pid = this.processService.getPid(systemProcess);
        try (final BufferedReader reader = new BufferedReader(new InputStreamReader(systemProcess.getInputStream()));
            final OutputStream os = systemProcess.getOutputStream())
        {
            ProcessCallable.LOGGER.debug("PID: {}", pid);
            String line = this.timeLimiter.callWithTimeout(reader::readLine, this.getTimeout(), this.getTimeoutUnit(), true);
            while (line != null)
            {
                ProcessCallable.LOGGER.debug("line: \"{}\"", line);
                line = this.timeLimiter.callWithTimeout(reader::readLine, this.getTimeout(), this.getTimeoutUnit(), true);
            }
        }
        final int exitCode = systemProcess.waitFor();
        ProcessCallable.LOGGER.debug("exit code for PID: {} = {}", pid, exitCode);
    }
    catch (final Exception ex)
    {
        ProcessCallable.LOGGER.error("error while executing command: " + this.process.getCommand(), ex);
        this.processService.killTree(systemProcess);
    }

    ...
}

Бревно

[2018-05-06 07:06:32] [DEBUG] [?.process.ProcessCallable] [processRunner1] executing command: /etc/init.d/starbound update ||| timeout: 1 MINUTES
[2018-05-06 07:06:32] [DEBUG] [?.service.ProcessService] [processRunner1] getting PID of java.lang.UNIXProcess
[2018-05-06 07:06:32] [DEBUG] [?.process.ProcessCallable] [processRunner1] PID: 15258
[2018-05-06 07:06:32] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "Updating Starbound Daemon"
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "Redirecting stderr to '/home/steam/logs/stderr.txt'"
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "Looks like steam didn't shutdown cleanly, scheduling immediate update check"
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "[  0%] Checking for available updates..."
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "[----] Verifying installation..."
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "Steam Console Client (c) Valve Corporation"
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "-- type 'quit' to exit --"
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: "Loading Steam API...OK."
[2018-05-06 07:06:34] [DEBUG] [?.process.ProcessCallable] [processRunner1] line: ""
[2018-05-06 07:11:22] [ERROR] [?.process.ProcessCallable] [processRunner1] error while executing command: /etc/init.d/starbound update
com.google.common.util.concurrent.UncheckedTimeoutException: java.util.concurrent.TimeoutException
        at com.google.common.util.concurrent.SimpleTimeLimiter.callWithTimeout(SimpleTimeLimiter.java:143)
        at ?.process.ProcessCallable.call(ProcessCallable.java:84)
        at ?.process.ProcessCallable.call(ProcessCallable.java:32)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282)
        at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
        at com.sun.proxy.$Proxy544.call(Unknown Source)
        at org.springframework.security.concurrent.DelegatingSecurityContextCallable.call(DelegatingSecurityContextCallable.java:86)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.util.concurrent.TimeoutException
        at java.util.concurrent.FutureTask.get(FutureTask.java:205)
        at com.google.common.util.concurrent.SimpleTimeLimiter.callWithTimeout(SimpleTimeLimiter.java:130)
    ... 20 more

Мне действительно нужно время ожидания для каждой строки, а не для процесса. Общее время выполнения сильно варьируется, и я пытаюсь выяснить, не завис ли процесс, требуя, по крайней мере, некоторый вывод время от времени. Как видно из журнала, я ждал около 5 минут (5 * тайм-аут), чтобы Java / SimpleTimeLimiter определил тайм-аут, прежде чем я наконец решил убить процесс из консоли. После уничтожения процесса, TimeoutException фактически выбрасывается. Мне трудно понять, почему future.get(timeoutDuration, timeoutUnit) не может правильно отключить блокирующий вызов BufferedReader.readLine (). Я почти уверен, что успешно использовал future.get() с таймаутами и Input-/OutputStreams в прошлом (на работе, хотя я даже не знал о TimeLimiter). Так в чем здесь проблема? Это основной Process?