Perl launched from Java takes forever

Question

I know this is an absolute shot in the dark, but we're absolutely perplexed.

A perl (5.8.6) script run by Java (1.5) is taking more than an hour to complete. The same script, when run manually from the command line takes 12 minutes to complete. This is on a Linux host.

Logging is the same in both cases and the script is run with the same parameters in both cases.

The script does some complex stuff like Oracle DB access, some scp's, etc, but again, it does the exact same actions in both cases.

We're stumped. Has anyone ever run into a similar situation? If not and if you were faced with the same situation, how would you consider debugging it?

Answer 1

I assume you've discarded the possibility that the Java wrapper happens to run simultaneously as something else which causes huge contention over some scarce resource? Good.

If you have a simple class like this:

public class Exec {
    public static void main(String[] args) throws Throwable{
        class Transfer implements Runnable {
            private final InputStream in; 
            private final OutputStream out; 
            public Transfer(InputStream i, OutputStream o){
                in = i;
                out = o;
            }
            public void run(){
                try {
                    for (int i; (i = in.read()) != -1;) out.write(i);
                    out.close();
                    in.close();
                } catch (IOException e) {
                    e.printStackTrace();
                } 
            }
        }
        Process proc = new ProcessBuilder(args).start();
        new Thread(new Transfer(System.in, proc.getOutputStream())).start();
        new Thread(new Transfer(proc.getInputStream(), System.out)).start();
        new Thread(new Transfer(proc.getErrorStream(), System.err)).start();
        System.exit(proc.waitFor());
    }
}

... and you compare time perl script.pl insert args here and time java Exec perl script.pl insert args here, what happens? If the world is sane, they take about the same time (except that the second one needs a few seconds extra for Java to start), and if that's the case, gradually start adapting the Exec class to look more and more like your deployment environment, and see when it starts taking a really long time.

If Exec above really does take longer time, start logging like crazy in the Perl script, so you see which actions take longer time. And btw, log in the Java wrapper, too, so you see if the Perl startup takes a really long time or something.

Answer 2

One possibility is that you are making the system thrash by trying to run a large Java app and a large Perl app on a system that doesn't have enough memory.

It would be a good idea to use monitoring utilities like top vmstat -5 iostat -5 etc to try and figure out if the slowness corresponds to some OS-level pathology.

Answer 3

Sub-proceses which produce console output can block (and deadlock) if their stdout/stderror streams are not flushed. @gustafc, the code posed will eventually block the sub-process when it tries to write to stdout/stderror, and there is no room in the stream (and the stream is not being serviced by java).

Process p = startProcess();

final InputStream stdout = p.getInputStream();
final InputStream sterr = p.getErrorStream();

new Thread() {
 public void run() {
  int c;
  while ((c = sterr.read()) != -1) {
   System.out.print((char)c);
  }
 }
}.start();

new Thread() {
 public void run() {
  int c;
  while ((c = sterr.read()) != -1) {
   System.out.print((char)c);
  }
 }
}.start();

Answer 4

To bring this thread to a close, the eventual cause was rogue processes consuming too much CPU. When launched from the command-line, the script had normal priority. When launched from Java, the script had low priority and thus took forever to execute. What threw us off was that the Java code was not just executing the script, it was issuing the same commands via SSH that we issued interactively. Thus, we didn't expect the difference in priority.