JDK-7090324: gclog rotation via external tool (original) (raw)

Yasumasa Suenaga yasu at ysfactory.dip.jp
Wed Feb 12 06:32:11 PST 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 shouldrotate? The old check just checked that byteswritten > GCLogFileSize. Default value of GCLogFileSIze is "0" in globals.hpp . So if this state is missed, shouldrotate() 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 < NUMLOGS; times++) {_ _// Run jcmd GC.rotatelog JDKToolLauncher jmap = JDKToolLauncher.create("jmap") .addToolArg(pid) .addToolArg("GC.rotatelog"); 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 rotatelog() to redirect messages to jcmd. If GC.rotatelog is executed, we can get messages on jcmd console as below: ------------ $ jcmd 18976 GC.rotatelog 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 checkgclogconsistency? In current implementation, checkgclogconsistency() 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::rotatelog method now does a lot of things. Could you separate out the first block into a new method, gcLogFileStream::shouldrotate(bool force)? This was, the code would read: bool gcLogFileStream::shouldrotate(bool force) { return force || byteswriten>= GCLogFileSize; } void gcLogFileStream::rotatelog(bool force) { char timemsg[FILENAMEBUFLEN]; char timestr[EXTRACHARLEN]; char currentfilename[FILENAMEBUFLEN]; char renamedfilename[FILENAMEBUFLEN]; if (!shouldrotate(force)) { return; } ... } Could you please update your patch? I will do that. There is a new empty line in the rotatelog method: } + #ifdef ASSERT could you please remove it? I will do that. The logging change in rotatelog 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: + jiosnprintf(timemsg, sizeof(timemsg), "%s GC log rotation request has been received. Saved as %s\n", + os::localtimestring((char *)timestr, sizeof(timestr)), + renamedfilename); + } + else { + jiosnprintf(timemsg, sizeof(timemsg), "%s GC log file has reached the" " maximum size. Saved as %s\n", - os::localtimestring((char *)timestr, sizeof(timestr)), + os::localtimestring((char *)timestr, sizeof(timestr)), renamedfilename); 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"; jiosnprintf(msg, os::localtimestring((char *)timestr, sizeof(timestr)), renamedfilename); I will do that. The declaration of rotatelog in ostream.hpp still uses the old variable name isforce, 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. VMGCOperation::doitprologue() etc...

src/share/vm/runtime/vmoperations.hpp line 402: nit: missing space before { Fixed. line 405: I think ‘force’ is a better name than ‘isforce’ 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 ‘isforce’ 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