Please review this fix for problem 1 described below. The patch is
basically what Ralf suggested.
Bug: https://bugs.openjdk.java.net/browse/JDK-8207001
Webrev: http://cr.openjdk.java.net/~erikj/8207001/webrev.01/
/Erik
On 2018-07-10 10:34, Erik Joelsson wrote:
Hello Ralf,
Very interesting analysis! I have spent a lot of time trying to get
the piping to log files, while keeping out/err separation working with
as little performance impact as possible. I was aware of problem 3,
which causes some annoying output ordering sometimes, but I had not
encountered 1 and 2 before. Checking my latest local Windows build, I
do indeed have some truncated files, not as many as you, but still 79
(less virus scanning). That would certainly make incremental builds
unreliable.
I tried your suggestion for problem 1 and it works for me too. We
should definitely get that fix in. I have filed JDK-8207001. Do you
mind if I use your patch for it?
I agree on the only solution for the 3rd problem, but I would not want
to go there. Delaying output can have lots of weird consequences, if
you for example interrupt a build with ctrl-c.
Another option would be to revert to our previous solution, where we
used this script:
http://hg.openjdk.java.net/jdk8u/jdk8u/file/090b27d25e19/common/bin/logger.sh
The problem with that was performance as it created more extra shell
instances for each compile command.
The only solution to fix problem 2 would be to stop separating
out/err. I wonder how big of a problem that actually is though?
/Erik
On 2018-07-10 05:34, Schmelter, Ralf wrote:
Hi,
while building openjdk on Windows, I've stumbled over a problem which
leads to truncated *.obj.log files, which in turn leads to empty
dependency files (which are generated from the contents of the
*.obj.log files on Windows). In the end, the incremental build will
not be reliable.
The reason seems to be this code from the ExecuteWithLog macro in
common/MakeBase.gmk:
( $(strip $2) > >($(TEE) $(strip $1).log) 2> >($(TEE) $(strip $1).log
>&2) || \
...
This executes the command given in $2 and tries to write
stdout/stderr to the file given by $1 and to 'normal' stdout/stderr
via process substitution. But it has a few problems.
The first problem occurs when the stdout-tee truncates the file, then
it writes some of the input it got into the file and only after this
the stderr-tee has run far enough to truncate the same file, which
leads to the loss of at least a part of stdout.
Another problem appears when the command writes to stdout and stderr.
Since each tee has its own file position, they would overwrite one
another.
The third problem arises because when the command $2 has ended, the
bash shell will not wait for the process substitutions (the two tee
commands) to end and instead will process the next command. Here we
try to copy the log file in case of an error. But the tee commands
might not have written the whole input they have got, so not the
whole content of the file might get copied.
In my case it seems to be the first problem which I see most. When
doing a fresh build on my Windows machine (which has quite an
aggressive virus scanner active), I get something like the following:
find . -name "*.obj.log" -size 0 | wc -l
424
find . -name "*.obj.log" -not -size 0 | wc -l
1603
Which means about 20% of the *.obj.log files are truncated.
When I replace the code above with:
( $(strip $2) > >($(TEE) $(strip $1).log) 2>&1 || \
...
I see no more truncated *.obj.log files. The cost is that stderr is
redirected to stdout (since the >&2 of the second tee is missing).
The last problem can be avoided by using something like:
($(RM) -f $(strip $1).log && $(strip $2) > >($(TEE) -a $(strip
$1).log) 2> >($(TEE) -a $(strip $1).log >&2) || \
...
This also leads to no truncated files, but the relative order of
stdout/stderr might be wrong.
If the third problem should be solved too, the only solution I've
found was to redierect via > $(strip $1).log 2>&1 to the file and
then later use 'cat' to write the output to stdout (losing the
distinction between stdout and stderr).
Best regards,
Ralf