RFR: 8219149: ProcessTools.ProcessBuilder should print timing info for subprocesses

[David Holmes]

Adding back hotspot-dev. I don't think Kim saw this.

David

On 30/05/2019 4:04 am, Roger Riggs wrote:
> Hi Kim,
> 
> In the normal output less output is cleaner.
> It would be more useful to have the Duration of the wait and end time of 
> the wait.
> (It saves the reader doing subtraction of times).
> 
> +          Instant start = Instant.now();
> +          boolean aborted = true;
> +          try {
> +              int result = p.waitFor();
> +              aborted = false;
> +              return result;
> +          } finally {
> +              Duration dur = Duration.between(start, Instant.now());
> +              if (aborted) {
> +                  logProgress("Waiting for completion FAILED after: " + 
> dur);
> +              } else {
> +                  logProgress("Waiting for completion finished after: " 
> + dur);
> +              }
> +          }
> 
> Or something like that.
> 
> Roger
> 
> 
> On 05/29/2019 01:24 PM, Kim Barrett wrote:
>> [I’m not completely sure where this RFR should be sent, but core-libs-dev
>> and hotspot-dev seems likely to get reasonable coverage of those who
>> might care.]
>>
>> Please review this change to the test library to add some "logging"
>> output to tests that spawn a child process to perform the test and
>> then analyze that child's output.  We are seeing occasional timeouts
>> in such tests whose cause is hard to pin down.  It's not clear whether
>> the excess time is in the child or instead some problem in the testing
>> framework.  The new logging output provides timestamps for (1) the
>> start of output collection from the child, (2) the start of waiting
>> for the child to terminate, and (3) the child's termination.  This
>> should be enough to determine whether the child is taking too long,
>> and hint at where (e.g. termination or not).
>>
>> CR:
>> https://bugs.openjdk.java.net/browse/JDK-8219149
>>
>> Webrev:
>> http://cr.openjdk.java.net/~kbarrett/8219149/open.00/
>>
>> Testing:
>> Local hs-tier1 and verified the expected logging output is present.
>> mach5 tier1-3 to ensure there aren't any "obvious" unexpected problems
>> caused by the new logging.  (It seems unlikely, but...)
>>
>>
>