JDK-7090324: gclog rotation via external tool
Yasumasa Suenaga
yasu at ysfactory.dip.jp
Wed Feb 12 14:32:11 UTC 2014
Hi all,
I've uploaded new webrev:
http://cr.openjdk.java.net/~ysuenaga/JDK-7090324/webrev.05/
Erik pointed me that my patch changes current behavior for GCLogFileSize.
In current implementation, default value of GCLogFileSize is set to "0" and
if user set this value to less than 8K, JVM adjust it to 8K.
Below are the scenarios:
1. -Xloggc:test.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=3
Should result in GCLogFileSize "0" (GC log rotation will be
turned off)
2. -Xloggc:test.log -XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=3 -XX:GCLogFileSize=10K
Should result in GCLogFileSize 10K
3. -Xloggc:test.log -XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=3 -XX:GCLogFileSize=2K
Should result in GCLogFileSize 8K
From the result of 3, we can think that GCLogFileSize is set to 8K by
default.
So I want to change default value of this to 8K in globals.hpp .
And I want to treat "0" as special number for rotating by external trigger.
From the result of 1, if GCLogFileSIze is set to "0",
UseGCLogFileRotation is set to false.
Definition of GCLogFileSize in globals.hpp, "0" means "no rotation" .
Thus I think this changes does not make different behavior from current
implementation.
------------------------
product(uintx, GCLogFileSize,
0, \
"GC log file size (default: 0 bytes, no rotation).
" \
"It requires
UseGCLogFileRotation") \
------------------------
Could you review this ?
Thanks,
Yasumasa
On 02/05/2014 09:13 PM, Yasumasa Suenaga wrote:
> 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 hotspot-gc-dev
mailing list