RFR: 7164841: Improvements to the GC log file rotation

[Yumin Qi]

Thanks review again.

On 9/10/2013 1:27 PM, Lois Foltan wrote:
> Hi Yumin,
>
> arguments.cpp - looks good, no comments
> ostream.hpp - looks good, no comments
>
> ostream.cpp -
>
>  - line #428 comment, word "contain" should be "contains"
>  - line #443 comment, word "contain" should be "contains"
Done the change.
>  - Did my earlier comment concerning the following issue get fixed?
>             - In rotatingFileStream::rotate_log(), I still have 
> questions about the error situation where the next file
>               in the rotation can not be opened.  The current file was 
> closed at line #619, UseGCLogFileRotation is
>               turned off at line #675, so how will the current file be 
> reopened to accommodate for the next write in
>               rotatingFileStream::write()?
>
When _file = fopen(...) failed, the rotation will be turned off, so any 
writing to the file will cause error.  But that will not happen:

0) When rotate_log called, it checks if the file is maximized, if not 
return; if maximized do
1) closed this file.   The file name is filename.i.current
2) check if filename.i exists, if it exists, delete it.
3)  a) if delete failed, the filename will remain as filename.i.current, 
since we have no way to delete filename.i, rename  filename.i.current to 
it will fail too, so the decision is no renaming. (next, when this file 
name encountered, it will be override since open will open same name,)
       b) if delete OK, the file is renamed as filename.i
4) next file name formed, filename.i+1.current
5) open this file.
      a) if open OK, writing header information to it. Then try to 
delete filename.i+1 if it exists.
          a1) deleting could fail, so just gives warning, cannot delete 
this file. This does not affect opened file (filename.i+1.current) 
operation. so the writing goes on til at safepoint  we come to  0) again.
          a2) delete OK  and go on til at safepoint we come to 0) again.
      b) if open failed.
           The log rotation turned off, not only log rotation turned 
off, since the file is not opened, any writing to the file will fail, 
but we have preventing code in write() that only _file is not NULL we 
make the writing. (update_position under such case does no make sense, 
but OK since no harm), this is piece of it:

void gcLogFileStream::write(const char* s, size_t len) {
   if (_file != NULL) {
     size_t count = fwrite(s, 1, len, _file);
     _bytes_written += count;
   }
   update_position(s, len);
}


Thanks
Yumin
> Thanks,
> Lois
>
>
> On 9/9/2013 3:11 PM, Yumin Qi wrote:
>> Hi, Thomas and all
>>
>>   This is a new version,
>> http://cr.openjdk.java.net/~minqi/7164841/webrev04/ 
>> <http://cr.openjdk.java.net/%7Eminqi/7164841/webrev04/>
>>
>>   There is an existing method, make_log_name which converts %p to 
>> <1234>, so I decided to modify it to include converting %t to 
>> YYYY-MM-DD_HH-MM-SS. The function extend_file_name is not needed 
>> then.  The name limitation is only for file name not path, in case 
>> user has special characters used in their path name.
>>
>>   rotatingFileStream is renamed to gcLogFileStream, and handle both 
>> logging (normal) and rotating work.
>>
>>   A problem observed when user gives an wrong path, say, 
>> -Xloggc:/temp/temp/test.log, /temp/temp does not exist, in this case, 
>> I only give a warning and not exit from VM, should app exit VM in 
>> such case? After warning, app still can run but no log.
>>
>>   Thanks
>>   Yumin
>>
>>
>>
>>
>> On 9/6/2013 3:27 AM, Thomas Schatzl wrote:
>>> hi,
>>>
>>> On Wed, 2013-09-04 at 19:35 -0700, Yumin Qi wrote:
>>>> Hi, Lois and all
>>>>
>>>>    This is fourth version after suggestions from Lois,
>>>>    URL: http://cr.openjdk.java.net/~minqi/7164841/webrev03
>>>>
>>>>    Add a function dump_loggc_header to fileStream to dump vm version
>>>> etc information as reusable function.
>>>>    Also some minor format and comments changes.
>>> Some notes (I hope this is the most recent patch, the thread is really
>>> long now):
>>>
>>> - The error string in Arguments::parse_each_vm_init_arg() contains a
>>> typo:
>>>
>>> 2857        jio_fprintf(defaultStream::output_stream(),
>>> 2858                   "Filename can only cantain 
>>> [A-Z][a-z][0-9]-_.%%[p|t]\n"
>>> 2859                   "%%p and %%t can only show up once\n" );
>>>
>>>
>>> "contain" instead of "cantain". Maybe add full stops after each 
>>> sentence
>>> (and quote the list of allowed characters). It may also be useful to
>>> show the user the bad string again.
>>>
>>> I.e. something like:
>>>
>>> Invalid file name for use with -Xloggc: Filename can only contain the
>>> characters .... but has been "string".
>>>
>>> - insertion of the time and pid strings seem to be coded somewhat
>>> complicated. I.e. it looks like
>>>
>>> if (both time and pid strings in file name) {
>>>    insert time string
>>>    insert pid string
>>> } else if (only time string in file name) {
>>>    insert time string
>>> } else if (only pid string in file name) {
>>>    insert pid string
>>> }
>>>
>>> but wouldn't it be simpler to do that in one go? I.e.
>>>
>>> given a file_name string of the format AAAA%aBBBB%bCCCC (may degenerate
>>> into BBBBB%bCCCC), you could copy first everything up until %a (the
>>> first marker), insert the first marker string, add BBBB, add the second
>>> marker string, and then add CCCC.
>>>
>>> I.e. something *like* this (not tested, may crash etc).
>>>
>>> // note: we already made sure that there is something to replace here,
>>> i.e. at least one of pp/pt is >= 0
>>>
>>> if (pp < pt) {
>>> pos_first = pp; // <--- instead of pp something like pos_pid would read
>>> better btw
>>> str_first = pidtext;
>>> pos_second = pt;
>>> str_second = timestr;
>>> } else {
>>> pos_first = pt;
>>> str_first = timestr;
>>> pos_second = pp;
>>> str_second = pidtext;
>>> }
>>>
>>> // if one of the replacement string has not been set (i.e. pos_first is
>>> -1), it is the first one now
>>>
>>> (note: why does timestr has a "str" suffix but pid a "text" one?)
>>>
>>> size_t copied_file_name_chars = 0; // number of chars copied so far 
>>> from
>>> file_name
>>> if (pos_first > 0) { // if there is a first marker
>>>    size_t length_to_copy = pos_first + 1;
>>>    strncat(extended_name, file_name, length_to_copy); // copy AAAA 
>>> part.
>>>    strcat(extended_name, str_first); // add first marker string
>>>    copied_file_name_chars += length_to_copy + 2; // remember that we
>>> already copied the AAAA part. 2 is the length of the replacement
>>> markers; maybe make a constant out of it.
>>> }
>>> size_t length_to_copy = pos_second - copied_file_name_chars + 1; // how
>>> long is the BBBB part?
>>> strncat(extended_name, file_name + copied_file_name_chars,
>>> length_to_copy); // add the BBBB part
>>> strcat(extended_name, str_second); // add the second marker
>>> copied_file_name_chars += length_to_copy + 2; // remember how much we
>>> copied from the file_name string
>>> strcat(extended_name, file_name + copied_file_name_chars); // copy CCCC
>>> part
>>>
>>> Untested :-)
>>>
>>> - not sure, but there seems to be a typo in the description of
>>> dump_loggc_header(): "header" instead of "head", "version" instead of
>>> "verison"
>>>
>>> - in fileStream::dump_loggc_header() there is a missing space after the
>>> "if"
>>>
>>> - why do we need an explicit "this->" use in
>>> fileStream::dump_loggc_header() to call the print member methods?
>>>
>>> - the change does the file name replacement for *all* file streams ever
>>> created by the VM. This seems unexpected, and is not documented at all
>>> in the ostream.hpp file. I would prefer if it would only be done for 
>>> the
>>> logging file.
>>> I.e. it is probably best to subclass fileStream with a gclogfilestream
>>> or whatever and use that for the log file. But maybe that has already
>>> been discussed - I haven't found anything about that though?
>>>
>>> - could you update the CR with the changed requirements? I.e. the
>>> introduction of the %p/%t etc and other limitations?
>>>
>>> Thanks,
>>> Thomas
>>>
>>
>