JDK-7090324: gclog rotation via external tool

Yasumasa Suenaga yasu at ysfactory.dip.jp
Wed Feb 5 04:09:04 PST 2014


Hi Erik,

Thank you for reviewing again!
I've updated new webrev.

On 02/05/2014 07:40 PM, Erik Helin wrote:
> Hi Yasumasa,
>
> I've looked through the latest patch, it is much better! I just have 
> two comments:
>
> - ostream.hpp:
>   Why did you add GCLogFileSize != 0 in should_rotate? The old check
>   just checked that _bytes_written > GCLogFileSize.

Default value of GCLogFileSIze is "0" in globals.hpp .
So if this state is missed, should_rotate() returns true in anytime.


> - TestGCLogRotationViaJcmd.java:
>   Could you use the helper class JDKToolLauncher to start jmap? The
>   code would then be slightly easier to read:
>
> for (int times = 1; times < NUM_LOGS; times++) {
>     // Run jcmd <pid> GC.rotate_log
>     JDKToolLauncher jmap = JDKToolLauncher.create("jmap")
>                                           .addToolArg(pid)
> .addToolArg("GC.rotate_log");
>     ProcessBuilder pb = new ProcessBuilder(jmap.getCommand());
>
>     // Make sure we didn't crash
>     OutputAnalyzer output = new OutputAnalyzer(pb.start());
>     output.shouldHaveExitValue(0);
> }

I've fixed. Could you check the patch?


Thanks,

Yasumasa


> Thanks,
> Erik
>
> On 01/30/2014 12:12 PM, Yasumasa Suenaga wrote:
>> Hi Staffan,
>>
>> I've uploaded new webrev:
>> http://cr.openjdk.java.net/~ysuenaga/JDK-7090324/webrev.03/
>>
>> On 2014/01/30 17:23, Staffan Larsen wrote:
>>> Would it be possible for the Diagnostic Command to output the location
>>> of the rotated log? When invoking the command it would be good to get
>>> some kind of feedback.
>>
>> I changed rotate_log() to redirect messages to jcmd.
>> If GC.rotate_log is executed, we can get messages on jcmd console as 
>> below:
>> ------------
>> $ jcmd 18976 GC.rotate_log
>> 18976:
>> 2014-01-30 19:59:39 GC log rotation request has been received. Saved as
>> test.log.0
>> 2014-01-30 19:59:39 GC log file created test.log.1
>> ------------
>>
>>
>>> test/gc/7090324/Test7090324.java:
>>> - I think this needs to have the Oracle copyright notice as well.
>>> - Tests should now use descriptive names, not bug numbers:
>>> https://wiki.openjdk.java.net/display/HotSpot/Naming+HotSpot+JTReg+Tests 
>>>
>>> - nits: lots of missing spaces before ‘{‘, and after ‘for’, ‘if’
>>> - line 47: you don’t need to clean up old files, jtreg will give you a
>>> fresh scratch directory to run in
>>
>> I've fixed.
>> Could you review again?
>>
>>
>> Thanks,
>>
>> Yasumasa
>>
>>> /Staffan
>>>
>>>
>>>
>>> On 30 jan 2014, at 08:08, Yasumasa
>>> Suenaga<suenaga.yasumasa at lab.ntt.co.jp>  wrote:
>>>
>>>> Hi Erik, Staffan,
>>>>
>>>> I've uploaded new webrev. Could you review this ?
>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-7090324/webrev.02/
>>>>
>>>> This patch includes fixes from comments of Staffan and Erik.
>>>>
>>>> And I created new test of this patch as Test7090324 .
>>>> This test works fine with jtreg.
>>>>
>>>>
>>>> Thanks,
>>>>
>>>> Yasumasa
>>>>
>>>> On 2014/01/30 0:55, Yasumasa Suenaga wrote:
>>>>> Hi Erik,
>>>>>
>>>>> On 2014/01/30 0:13, Erik Helin wrote:
>>>>>> Hi Yasumasa,
>>>>>>
>>>>>> (have to use HTML email to get a width of more than 78 chars, sorry)
>>>>>>
>>>>>> why did you change the code in arguments.cpp in the method
>>>>>> check_gc_log_consistency?
>>>>>
>>>>> In current implementation, check_gclog_consistency() checks three
>>>>> parameters:
>>>>>
>>>>> - GC log filename
>>>>> - NumberOfGCLogFiles
>>>>> - GCLogFileSize
>>>>>
>>>>> My customer uses external trigger "ONLY" for rotating logs.
>>>>> If they want to do that, GCLogFileSize does not need.
>>>>>
>>>>>
>>>>>> Next, the gcLogFileStream::rotate_log method now does a lot of 
>>>>>> things.
>>>>>> Could you separate out the first block into a new method,
>>>>>> gcLogFileStream::should_rotate(bool force)?
>>>>>>
>>>>>> This was, the code would read:
>>>>>>
>>>>>>> bool gcLogFileStream::should_rotate(bool force) {
>>>>>>> return force || _bytes_writen>= GCLogFileSize;
>>>>>>> }
>>>>>>>
>>>>>>> void gcLogFileStream::rotate_log(bool force) {
>>>>>>> char time_msg[FILENAMEBUFLEN];
>>>>>>> char time_str[EXTRACHARLEN];
>>>>>>> char current_file_name[FILENAMEBUFLEN];
>>>>>>> char renamed_file_name[FILENAMEBUFLEN];
>>>>>>>
>>>>>>> if (!should_rotate(force)) {
>>>>>>> return;
>>>>>>> }
>>>>>>>
>>>>>>> ...
>>>>>>> }
>>>>>>
>>>>>> Could you please update your patch?
>>>>>
>>>>> I will do that.
>>>>>
>>>>>
>>>>>> There is a new empty line in the rotate_log method:
>>>>>>
>>>>>>> }
>>>>>>> +
>>>>>>> #ifdef ASSERT
>>>>>>
>>>>>> could you please remove it?
>>>>>
>>>>> I will do that.
>>>>>
>>>>>
>>>>>> The logging change in rotate_log uses a different kind of if/else
>>>>>> syntax
>>>>>> than the rest of the file:
>>>>>>
>>>>>>> if (force) {
>>>>>>> ...
>>>>>>> }
>>>>>>> else {
>>>>>>> ...
>>>>>>> }
>>>>>>
>>>>>> The other if/else statements in the file uses:
>>>>>>
>>>>>>> if (cond) {
>>>>>>> ...
>>>>>>> } else {
>>>>>>> ...
>>>>>>> }
>>>>>>
>>>>>> Could you please update your change to use the same if/else syntax?
>>>>>
>>>>> I will do that.
>>>>>
>>>>>
>>>>>> This part of the change duplicates the code:
>>>>>>
>>>>>> + jio_snprintf(time_msg, sizeof(time_msg), "%s GC log rotation
>>>>>> request has been received. Saved as %s\n",
>>>>>> + os::local_time_string((char *)time_str, sizeof(time_str)),
>>>>>> + renamed_file_name);
>>>>>> + }
>>>>>> + else {
>>>>>> + jio_snprintf(time_msg, sizeof(time_msg), "%s GC log file has
>>>>>> reached the"
>>>>>> " maximum size. Saved as %s\n",
>>>>>> - os::local_time_string((char *)time_str, sizeof(time_str)),
>>>>>> + os::local_time_string((char *)time_str, sizeof(time_str)),
>>>>>> renamed_file_name);
>>>>>>
>>>>>> Could you instead just change the message, as in:
>>>>>>
>>>>>>> const char* msg = forced ? "%s GC log rotation request has been
>>>>>>> received. Saved as %s\n" :
>>>>>>> "%s GC log file has reached the maximum size. Saved as %s\n";
>>>>>>> jio_snprintf(msg, os::local_time_string((char *)time_str,
>>>>>>> sizeof(time_str)), renamed_file_name);
>>>>>
>>>>> I will do that.
>>>>>
>>>>>
>>>>>> The declaration of rotate_log in ostream.hpp still uses the old
>>>>>> variable name is_force, it should use force,
>>>>>> just as the definition.
>>>>>
>>>>> Sorry, I will fix it.
>>>>>
>>>>>
>>>>>> Finally, could you add a test that tests your change? Have a look
>>>>>> at the other tests
>>>>>> in hotspot/test/gc to see how you can do it
>>>>>> (you might want to use some functionality from
>>>>>> hotspot/test/testlibrary).
>>>>>
>>>>> I found three tests as following:
>>>>>
>>>>> [ysuenaga at xelvis test]$ find . -iname "*jcmd*"
>>>>> ./runtime/NMT/JcmdWithNMTDisabled.java
>>>>> ./runtime/NMT/JcmdScale.java
>>>>> ./gc/TestG1ZeroPGCTJcmdThreadPrint.java
>>>>>
>>>>> I understand that these tests checks output (stdout/stderr) with
>>>>> OutputAnalyzer.
>>>>> However, my patch affects target VM. So I guess current test cannot
>>>>> check
>>>>> that GC log rotation is succeeded.
>>>>>
>>>>> Should I make test which checks exit value of jcmd ?
>>>>>
>>>>>
>>>>> Thanks,
>>>>>
>>>>> Yasumasa
>>>>>
>>>>>> Thanks,
>>>>>> Erik
>>>>>>
>>>>>> On 2014-01-29 15:28, Yasumasa Suenaga wrote:
>>>>>>> Hi Staffan,
>>>>>>>
>>>>>>> Thank you for reviewing!
>>>>>>> I've uploaded new webrev.
>>>>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-7090324/webrev.01/
>>>>>>>
>>>>>>> On 2014/01/29 20:56, Staffan Larsen wrote:
>>>>>>>> Yasumasa,
>>>>>>>>
>>>>>>>> src/share/vm/runtime/arguments.cpp
>>>>>>>> no comments
>>>>>>>>
>>>>>>>> src/share/vm/runtime/safepoint.cpp
>>>>>>>> I was surprised that gc log size was checked after each safe
>>>>>>>> point. That seems an uneccssary burden to place on a safe point.
>>>>>>>> Instead we should switch to a periodic task that checks the gc
>>>>>>>> log size. However, this is unrelated to you patch, so please
>>>>>>>> ignore for now.
>>>>>>>
>>>>>>> Agree.
>>>>>>> However, I think that PeriodicTask also is not appropriate for 
>>>>>>> this.
>>>>>>>
>>>>>>> Size of GC log file is increased when GC is occurred.
>>>>>>> So I think rotate function should be called at entry of each GC
>>>>>>> events
>>>>>>> e.g. VM_GC_Operation::doit_prologue() etc...
>>>>>>>
>>>>>>>
>>>>>>>> src/share/vm/runtime/vm_operations.hpp
>>>>>>>> line 402: nit: missing space before {
>>>>>>>
>>>>>>> Fixed.
>>>>>>>
>>>>>>>
>>>>>>>> line 405: I think ‘force’ is a better name than ‘is_force’
>>>>>>>
>>>>>>> I removed "force" option from DCmd.
>>>>>>> So I removed this from VMOperation.
>>>>>>>
>>>>>>>
>>>>>>>> src/share/vm/services/diagnosticCommand.cpp
>>>>>>>> line 666: What does this do without the -force option? It looks
>>>>>>>> to me that the non-force case will happen after each safe point
>>>>>>>> (see above) and that there is no need to ever do this from a
>>>>>>>> diagnostic command. Can we remove the option?
>>>>>>>
>>>>>>> Indeed.
>>>>>>> I removed "force" option.
>>>>>>>
>>>>>>>
>>>>>>>> line 677: “Target VM does not support GC log file rotation."
>>>>>>>
>>>>>>> Fixed.
>>>>>>>
>>>>>>>
>>>>>>>> nits: some missing spaces before ‘{' and after ‘if'
>>>>>>>
>>>>>>> Fixed.
>>>>>>>
>>>>>>>
>>>>>>>> src/share/vm/services/diagnosticCommand.hpp
>>>>>>>> I think RotateGCLogDCmd should require the “control” permission
>>>>>>>> when executed via JMX, so please add:
>>>>>>>> static const JavaPermission permission() {
>>>>>>>> JavaPermission p = {"java.lang.management.ManagementPermission",
>>>>>>>> "control", NULL};
>>>>>>>> return p;
>>>>>>>> }
>>>>>>>
>>>>>>> Added.
>>>>>>>
>>>>>>>
>>>>>>>> line 394: Maybe “Force the GC log file to be rotated.” is a
>>>>>>>> better description?
>>>>>>>
>>>>>>> Fixed.
>>>>>>>
>>>>>>>
>>>>>>>> src/share/vm/utilities/ostream.cpp
>>>>>>>> line 662: I think ‘force’ is a better name than ‘is_force’
>>>>>>>> line 668: The comment says exactly the same thing as the code so
>>>>>>>> I think it can be skipped
>>>>>>>> line 671: “GC log file rotation occurs by external trigger ONLY."
>>>>>>>> line 675: "not need” ->  “no need”
>>>>>>>> line 718: "GC log rotation request has been received”
>>>>>>>
>>>>>>> Fixed them.
>>>>>>>
>>>>>>>
>>>>>>> Thanks,
>>>>>>>
>>>>>>> Yasumasa
>>>>>>>
>>>>>>>
>>>>>>>> src/share/vm/utilities/ostream.hpp
>>>>>>>> no comments
>>>>>>>>
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>> /Staffan
>>>>>>>>
>>>>>>>> On 24 jan 2014, at 14:50, Yasumasa
>>>>>>>> Suenaga<yasu at ysfactory.dip.jp>  wrote:
>>>>>>>>
>>>>>>>>> Hi all,
>>>>>>>>>
>>>>>>>>> I've created webrev:
>>>>>>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-7090324/webrev.00/
>>>>>>>>>
>>>>>>>>> This patch works fine on current jdk9/hs-rt .
>>>>>>>>> Could you review this?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> I am just an Author. So I need a sponsor.
>>>>>>>>> Could you help me?
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Please cooperate.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Thanks,
>>>>>>>>>
>>>>>>>>> Yasumasa
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On 2013/12/06 0:05, Yasumasa Suenaga wrote:
>>>>>>>>>> Hi all,
>>>>>>>>>>
>>>>>>>>>> Did someone read my email?
>>>>>>>>>> I really hope to merge "JDK-7090324: gclog rotation via
>>>>>>>>>> external tool" .
>>>>>>>>>>
>>>>>>>>>> I hear that someone need this RFE. So I want to discuss about
>>>>>>>>>> this.
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> Thanks,
>>>>>>>>>>
>>>>>>>>>> Yasumasa
>>>>>>>>>>
>>>>>>>>>> On 2013/11/08 21:47, Yasumasa Suenaga wrote:
>>>>>>>>>>> Hi all,
>>>>>>>>>>>
>>>>>>>>>>> Did someone read my mail?
>>>>>>>>>>>
>>>>>>>>>>> I think that this RFE helps us to watch Java heap on
>>>>>>>>>>> production system.
>>>>>>>>>>> Also I think this RFE is able to be part of the JEP 158
>>>>>>>>>>> (Unified JVM Logging) .
>>>>>>>>>>>
>>>>>>>>>>> I want to update this RFE in JDK Bug System, but I don't have
>>>>>>>>>>> account.
>>>>>>>>>>> So I've posted email at first.
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> Thanks,
>>>>>>>>>>>
>>>>>>>>>>> Yasumasa
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> On 2013/09/30 21:10, Yasumasa Suenaga wrote:
>>>>>>>>>>>> In previous email, I've attached new patch for this RFE.
>>>>>>>>>>>> It works fine with current hsx.
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> Yasumasa
>>>>>>>>>>>>
>>>>>>>>>>>> On 2013/09/29 23:40, Yasu wrote:
>>>>>>>>>>>>> Hi all,
>>>>>>>>>>>>>
>>>>>>>>>>>>> We are using "logrotate" tool on RHEL for various log 
>>>>>>>>>>>>> rotation.
>>>>>>>>>>>>> Current HotSpot has gclog rotation function for log size 
>>>>>>>>>>>>> base,
>>>>>>>>>>>>> however I need to rotate gc log synchronizing with logrotate
>>>>>>>>>>>>> tool.
>>>>>>>>>>>>>
>>>>>>>>>>>>> So I've created RFE as "JDK-7090324: gclog rotation via
>>>>>>>>>>>>> external tool" .
>>>>>>>>>>>>> And Sr. Engineering Manager in Oracle said he use the
>>>>>>>>>>>>> essence of my patch in one
>>>>>>>>>>>>> of the jcmd subcommands.
>>>>>>>>>>>>> http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/2011-September/003274.html 
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> 2 years ago, I posted a patch for this RFE.
>>>>>>>>>>>>> But this patch is too old to apply for current HotSpot.
>>>>>>>>>>>>>
>>>>>>>>>>>>> In last month, a similar discussion was appeared in ML.
>>>>>>>>>>>>> So I think it's time to discuss this RFE.
>>>>>>>>>>>>> http://mail.openjdk.java.net/pipermail/hotspot-gc-dev/2013-August/008029.html 
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> Please cooperate.
>>>>>>>>>>>>>
>>>>>>>>>>>>> Best regards,
>>>>>>>>>>>>> Yasumasa
>>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>
>>
>



More information about the hotspot-gc-dev mailing list