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

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, 
> va_list args) {
>   char buf[LogBufferSize];
>   static const size_t 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.puts<LogLevel::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 
> ATTRIBUTE_PRINTF, it doesn't seem to do the checking.
>
>   static void write(const char* fmt, ...) ATTRIBUTE_PRINTF(1, 2);
>
> I added these
>
> void LogConfiguration::post_initialize() {
>   assert(LogConfiguration_lock != NULL, "Lock must be initialized 
> before post-initialization");
>   LogDiagnosticCommand::registerCommand();
>   LogHandle(logging) log;
>   log.info("Log configuration fully initialized.");
> + log_info(logging)("hello %s");
> + tty->print_cr("hello %s");
>
> I get a warning on the tty->print_cr line but not on the 
> log_info(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::post_initialize()':
> /home/iklam/jdk/ul/hotspot/src/share/vm/logging/logConfiguration.cpp:52:27: 
> error: format `%s' expects a matching `char*' argument [-Werror=format=]
>    tty->print_cr("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.
> COLLECT_GCC=gcc
> COLLECT_LTO_WRAPPER=/usr/lib/gcc/x86_64-linux-gnu/4.8/lto-wrapper
> Target: x86_64-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=x86_64-linux-gnu 
> --host=x86_64-linux-gnu --target=x86_64-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:
>>>>
>>>> +    log_error(logging)("%s", errbuf);
>>>> +    log_error(logging)("Could not open log file '%s' (%s).\n", 
>>>> _file_name, 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
>>>>
>>>
>>
>