JDK-7090324: gclog rotation via external tool

Erik Helin erik.helin at oracle.com
Wed Feb 5 02:40:30 PST 2014


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.

- 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);
}

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