RFR (L): 8046148: JEP 158 Unified JVM Logging (original) (raw)

Marcus Larsson marcus.larsson at oracle.com
Fri Sep 11 13:26:45 UTC 2015

Hi,

Thanks for your input.

On 2015-09-10 19:57, Ioi Lam wrote:

I have two issues:

[1] There's a limit of 512 characters: void Log<T0, T1, T2, T3, T4, GuardTag>::vwrite(const char* fmt, valist args) { char buf[LogBufferSize]; static const sizet LogBufferSize = 512; I would need to log the names of loaded classes, which could be much longer. Would it be possible to add a new function like LogHandle(classload) log; log.putsLogLevel::Info("a very very very long string ..........");

This seems like a reasonable idea to me if you need such functionality.

[2] Although the Log::write function is declared with ATTRIBUTEPRINTF, it doesn't seem to do the checking. static void write(const char* fmt, ...) ATTRIBUTEPRINTF(1, 2); I added these void LogConfiguration::postinitialize() { assert(LogConfigurationlock != NULL, "Lock must be initialized before post-initialization"); LogDiagnosticCommand::registerCommand(); LogHandle(logging) log; log.info("Log configuration fully initialized."); + loginfo(logging)("hello %s"); + tty->printcr("hello %s"); I get a warning on the tty->printcr line but not on the loginfo(logging) line. NOTICE Dtrace support disabled: This JDK does not support SDT probes /home/iklam/jdk/ul/hotspot/src/share/vm/logging/logConfiguration.cpp: In static member function static void_ _LogConfiguration::postinitialize()':_ _/home/iklam/jdk/ul/hotspot/src/share/vm/logging/logConfiguration.cpp:52:27:_ _error: format %s' expects a matching `char*' argument [-Werror=format=] tty->printcr("hello %s"); ^ cc1plus: all warnings being treated as errors make[4]: *** [logConfiguration.o] Error 1

That's weird. It seems the printf-attribute is lost when splitting the function definition from the declaration. When I merge them the warning appears as it should. Will update the patch with this fix!

Thanks, Marcus

My gcc is $ gcc -v Using built-in specs. COLLECTGCC=gcc COLLECTLTOWRAPPER=/usr/lib/gcc/x8664-linux-gnu/4.8/lto-wrapper Target: x8664-linux-gnu Configured with: ../src/configure -v --with-pkgversion='Ubuntu 4.8.2-19ubuntu1' --with-bugurl=file:///usr/share/doc/gcc-4.8/README.Bugs --enable-languages=c,c++,java,go,d,fortran,objc,obj-c++ --prefix=/usr --program-suffix=-4.8 --enable-shared --enable-linker-build-id --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --with-gxx-include-dir=/usr/include/c++/4.8 --libdir=/usr/lib --enable-nls --with-sysroot=/ --enable-clocale=gnu --enable-libstdcxx-debug --enable-libstdcxx-time=yes --enable-gnu-unique-object --disable-libmudflap --enable-plugin --with-system-zlib --disable-browser-plugin --enable-java-awt=gtk --enable-gtk-cairo --with-java-home=/usr/lib/jvm/java-1.5.0-gcj-4.8-amd64/jre --enable-java-home --with-jvm-root-dir=/usr/lib/jvm/java-1.5.0-gcj-4.8-amd64 --with-jvm-jar-dir=/usr/lib/jvm-exports/java-1.5.0-gcj-4.8-amd64 --with-arch-directory=amd64 --with-ecj-jar=/usr/share/java/eclipse-ecj.jar --enable-objc-gc --enable-multiarch --disable-werror --with-arch-32=i686 --with-abi=m64 --with-multilib-list=m32,m64,mx32 --with-tune=generic --enable-checking=release --build=x8664-linux-gnu --host=x8664-linux-gnu --target=x8664-linux-gnu Thread model: posix gcc version 4.8.2 (Ubuntu 4.8.2-19ubuntu1) Thanks - Ioi On 9/9/15 12:33 AM, Marcus Larsson wrote: Hi,

On 2015-09-08 22:53, Ioi Lam wrote: Also, is it possible to combine the output of two tags into a single file, like this?

-Xlog:gc:file=out.txt -Xlog:comp:file=out.txt this way, I can have both GC and Compiler logs that's in an (approximate) temporal order. The alternatives are: - write both to stdout -- but I need to filter out junk that I don't want - write to different files -- but I lose the relative ordering between the two sets of logs From the current patch, it seems like if I assign the same file name to two tags, fopen() will be called twice and the result will be platform dependent. - Ioi This is indeed possible! The syntax for configuring this would be -Xlog:gc,comp:file=out.txt. Configuring logging for the same output multiple times only overrides/replaces the previous configuration. The second fopen will not happen, because the log configuration will notice the output already exists and simply reconfigure the existing output. Thanks, Marcus

On 9/8/15 1:26 PM, Ioi Lam wrote: Hi Marcus, I am eagerly waiting for this to implement a new logging feature in the VM. How much testing has been done on this patch? I can see only two locations where any logs are bring generated: + logerror(logging)("%s", errbuf); + logerror(logging)("Could not open log file '%s' (%s).\n", filename, strerror(errno)); Do you have a follow-on patch that's already in work to test the various functionalists of the Unified JVM Logging framework? I am asking so that I can know how much surprise to expect when I start using it. Thanks - Ioi

On 9/7/15 6:33 AM, Marcus Larsson wrote: Hi, Please review the following patch adding the unified logging framework to hotspot. JEP: https://bugs.openjdk.java.net/browse/JDK-8046148 Webrev: http://cr.openjdk.java.net/~mlarsson/8046148/webrev.00/ See the JEP description for a general overview of the new feature. Below are some notes on the implementation. The patch adds the new 'share/vm/logging' subdirectory containing the unified logging framework. The main entry point is log.hpp, which contains the necessary macros and definitions to use the framework. Log tags are defined/listed in logTag.hpp, and are passed as template arguments to the Log class. Every combination of tags used in a log call has a corresponding LogTagSet instance, which keeps a track of all the outputs it should write the log message to (and their levels). Having tags as template arguments allows mapping directly from a set of tags to the LogTagSet instance, which means that the overhead for disabled logging should be low. Currently each log message can be tagged with up to 5 tags, but this can be increased if ever required (and with C++11's variadic templates the limit can be removed completely). The LogConfiguration class keeps track of configured outputs (stdout, stderr, and possible file outputs). Configuration is done either by command line arguments (-Xlog) or by DCMD. Both methods will in turn use the LogConfiguration class to perform the parsing & configuration. This configuration includes iterating over all LogTagSet instances and updating them accordingly. The LogTagLevelExpression class is used to represent the selection of tags and levels for a given configuration request (the "what"-expression). The LogDecorators class contains a selection of decorators. Instances of this class is kept in LogTagSet to track what decorators to use (this is the union of all decorators used by its outputs). Each log call will create a LogDecorations instance (note: different classes), which will contain the actual decoration strings for the log message. These decorations are used for each output the tagset is set to log on, and are then discarded. The LogPrefix class allows messages of specific sets of tags to be prefixed. The prefix should supply a printf-style format with argument. (This allows GC logging to prefix messages of certain tagsets with GCId.) Prefixes are implemented using template specializations based on the specified tags, with the general/unspecialized case giving an empty prefix. The LogOutput class defines the interface for all types of log outputs. LogFileStreamOutput corresponds to FILE* stream based log outputs. LogFileOutput builds on this and adds the file management and log rotation support. A simple jtreg test is included in this patch. Additional tests will be added at a later stage. Thanks, Marcus

More information about the hotspot-dev mailing list