JDK-7090324: gclog rotation via external tool

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

Sorry, I forgot to paste URL of new webrev :-P
http://cr.openjdk.java.net/~ysuenaga/JDK-7090324/webrev.04/


Yasumasa

On 02/05/2014 09:09 PM, Yasumasa Suenaga wrote:
> 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 serviceability-dev mailing list