Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8233725

ProcessTools.startProcess() has output issues when using an OutputAnalyzer at the same time

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Priority: P4
    • Resolution: Unresolved
    • Affects Version/s: 14, 15, 16, 17, 18
    • Fix Version/s: 18
    • Component/s: hotspot
    • Labels:
    • Subcomponent:

      Description

      If you use ProcessTools.startProcess() and apply an OutputAnalyzer right afterwards as shown below:

                  p = ProcessTools.startProcess("java", pb);
                  out = new OutputAnalyzer(p);

      Some of the output will end up with the OutputAnalyzer, and some automatically included in the .jtr file with the "[java]" prefix. It seems to be randomly divvied up between the two, whereas all the output should appear in both.

      Using the Consumer argument has a similar issue:

                  p = ProcessTools.startProcess("java", pb, outputConsumer);
                  out = new OutputAnalyzer(p);

      The lines that are directed to the Consumer are the same as the lines you see with the "[java]" prefix. The rest are directed to the OutputAnalyzer. The issue happens with both stdout and stderr.

      Please see the attached test case. It runs once with without a consumer and once with. I'm not certain you will always see both test cases fail on all processors since some of it might be timing related. For example, without a consumer I see:

      [2019-11-06T00:42:06.891310Z] Gathering output for process 27274
      DEBUG: process started.
      [java] A line on stdout 0
      FAILED: wrong number of lines in OutputAnalyzer output
      DEBUG: OutputAnalyzer output: got 49 lines, expected 50. Output follows:
      A line on stdout 1
      A line on stdout 2
      <...>

      So only the first line ended up with the "[java]" prefix. If it had instead ended up in the OutputAnalyzer output, the test would not have detected any failures because it can't actually see that were no lines of "[java]" output.

      The Consumer case which runs second seems to do a much better job of showing this issue, at least when run on my machine:

      [2019-11-06T00:42:06.923088Z] Gathering output for process 27297
      DEBUG: process started.
      [java] A line on stdout 0
      [java] A line on stdout 26
      [java] A line on stdout 30
      [java] A line on stdout 33
      [java] A line on stdout 35
      [java] A line on stdout 37
      [java] A line on stdout 39
      [java] A line on stdout 42
      [java] A line on stdout 44
      [java] A line on stdout 47
      [java] A line on stdout 49
      FAILED: wrong number of lines in Consumer output
      DEBUG: Consumer output: got 11 lines, expected 50. Output follow:
      A line on stdout 0
      A line on stdout 26
      A line on stdout 30
      A line on stdout 33
      A line on stdout 35
      A line on stdout 37
      A line on stdout 39
      A line on stdout 42
      A line on stdout 44
      A line on stdout 47
      A line on stdout 49
      DEBUG: done with Consumer output.
      FAILED: wrong number of lines in OutputAnalyzer output
      DEBUG: OutputAnalyzer output: got 39 lines, expected 50. Output follows:
      A line on stdout 1
      A line on stdout 2
      <...>
      A line on stdout 24
      A line on stdout 25
      A line on stdout 27
      A line on stdout 28
      A line on stdout 29
      A line on stdout 31
      A line on stdout 32
      A line on stdout 34
      A line on stdout 36
      A line on stdout 38
      A line on stdout 40
      A line on stdout 41
      A line on stdout 43
      A line on stdout 45
      A line on stdout 46
      A line on stdout 48

      So in this case here were 11 lines, scattered from throughout the output, that appeared with the "[java]" prefix and also with the Consumer. The rest were in the OutputAnalyzer.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              shurailine Aleksandre Iline
              Reporter:
              cjplummer Chris Plummer
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated: