[9] RFR(S): 8007993: hotspot.log w/ enabled LogCompilation can be an invalid XML

[Tobias Hartmann]

Thanks, Vladimir.

Best,
Tobias

On 24.11.2014 14:56, Vladimir Ivanov wrote:
> Looks good!
> 
> Best regards,
> Vladimir Ivanov
> 
> On 11/24/14, 5:20 PM, Tobias Hartmann wrote:
>> Hi,
>>
>> please review the following patch.
>>
>> Bugs: https://bugs.openjdk.java.net/browse/JDK-8007993
>> Webrev: http://cr.openjdk.java.net/~thartmann/8007993/webrev.00/
>>
>> Problem:
>> The per-thread compilation logs ('/tmp/hs_c[TID]_pid[PID].log') are deleted and
>> merged into one XML file at VM shutdown. The test fails because this compilation
>> log contains invalid XML. The bug only occurs on Windows.
>>
>> The problem is that the temporary, per-thread compilation logs are not deleted
>> on Windows because the file descriptor is not closed [1]. This seems to work on
>> Linux because the removal is not immediately executed and the file is closed
>> soon after the removal request. If a file for the current TID/PID combination
>> already exists, the log is appended [2]. At VM shutdown the per-thread logs are
>> read from the beginning until the number of written bytes is reached
>> ('CompileLog::_file_end'). The remaining data is appended with a <![CDATA[ ...
>> ]]> tag. If the file already exists, old data is read that may be shorter/longer
>> than the number of bytes previously written. Copying partial XML data into the
>> file breaks XML validity.
>>
>> For example, see the file '25996.log' [3]. The tag "<compilation_log
>> thread='6108'>" for thread 6108 contains "'C1 CompilerThread10" (line 3901) and
>> "C1 CompilerThread9" (line 3950) which is obviously wrong because a thread only
>> runs one compiler. The first log for compiler thread 10 is old data. As a result
>> not all log data for compiler thread 9 is read and the rest is appended within
>> CDATA tags (line 19093 until 19158). Further, we have two entries for
>> "CompilerThread10".
>>
>> Solution:
>> The log files should be opened in 'write' instead of 'append' mode to ensure no
>> old data is used. The log files should be closed prior to deletion. I moved the
>> call to 'unlink' to 'CompileLog::~CompileLog()' to ensure this.
>>
>> Testing:
>> - JPRT with failing testcase
>> - Executed 10k runs of the fixed version on different Windows machines
>>
>> Thanks,
>> Tobias
>>
>> [1] The file is closed by 'fileStream::~fileStream' but deletion is attempted
>> before that in 'CompileLog::finish_log_on_error'.
>> [2] See argument 'a'  to 'fopen' in 'CompileBroker::init_compiler_thread_log'
>> [3] https://bugs.openjdk.java.net/secure/attachment/23746/25996.log
>>