RFR: 8151526: Print -Xlog configuration in the hs_err_pid file

[Marcus Larsson]

On 04/11/2016 09:00 AM, Thomas Stüfe wrote:
> Hi Max,
>
> On Fri, Apr 8, 2016 at 9:56 PM, Max Ockner <max.ockner at oracle.com 
> <mailto:max.ockner at oracle.com>> wrote:
>
>     I forgot to respond to this:
>     On 4/1/2016 4:45 AM, Marcus Larsson wrote:
>>     Hi,
>>
>>     On 03/31/2016 08:08 PM, Max Ockner wrote:
>>>     (Replies in line)
>>>
>>>     On 3/30/2016 9:31 AM, Thomas Stüfe wrote:
>>>>     Hi Max,
>>>>
>>>>     Disclaimer: not a (R)eviewer.
>>>>
>>>>     Do we really need a list of all tags and all decorators?
>>>>
>>>     Just going by what we currently put in the hs_err file, I think
>>>     this may be the first "Do we really need" we've ever asked for
>>>     this type of change.
>>>
>>>     All joking aside, I think it is a good idea to direct users
>>>     toward proper UL usage whenever we have a chance.
>>>
>>>>     Also: I assume what you print is the Log state as it is at the
>>>>     time the hs-err file is printed. If logging was enabled/changed
>>>>     during lifetime of the VM, e.g. with jcmd, would it be possible
>>>>     to see that? At least a warning if logging was not enabled from
>>>>     the start on.
>>>>
>>>     Would it be possible? Yes, but I think this would require a
>>>     framework change. It does not look like any marks are made when
>>>     the LogConfiguration changes during runtime, and we would need
>>>     to record that in order to know what to print when we dump into
>>>     hs_err.
>>
>>     Yes, this would required the framework to keep some sort of log
>>     of configuration changes. Is there value in knowing that the log
>>     configuration changed since startup?
>
>     I think it is useful along with other information. An example case:
>
>     Let's say we are logging a message whenever a lock is acquired or
>     released. In a subsystem like this, the action which dooms the vm
>     may not cause an immediate crash. This leaves time for logging to
>     turn on or off in between the bad action and the crash. If you
>     don't know when logging was active and when it was not, then the
>     absence of a particular message does not give you much
>     information. You may not see the message that has the answer for
>     you because it was not logged, though the action may have occurred.
>
>     However, if we don't have the framework support for this then I
>     believe it should be added later.
>
>
>
> This is a good example. A small easy solution, as I mentioned before, 
> could be just to distinguish between "logging parameters stable since 
> startup" and "logging parameters changed at some time". That way you 
> would at least know whether to trust the logging output.
>
> But you are right, this can be added later.

I've filed https://bugs.openjdk.java.net/browse/JDK-8153945 for this.

Max: Did you see my comments about the ConfigurationLock? It was an 
inline reply to your first mail.

Thanks,
Marcus

>
> Kind Regards, Thomas
>
>
>>
>>>
>>>     Thanks,
>>>     Max
>>>>     Kind Regards, Thomas
>>>>
>>>>
>>>>
>>>>
>>>>     On Tue, Mar 29, 2016 at 9:00 PM, Max Ockner
>>>>     <max.ockner at oracle.com <mailto:max.ockner at oracle.com>> wrote:
>>>>
>>>>         Hello,
>>>>         Please review another Unified Logging change. They are
>>>>         almost done, and we are serious this time.
>>>>
>>>>         bug: https://bugs.openjdk.java.net/browse/JDK-8151526
>>>>         webrev: http://cr.openjdk.java.net/~mockner/8151526.01/
>>>>         <http://cr.openjdk.java.net/%7Emockner/8151526.01/>
>>>>
>>
>>     LogConfiguration::describe() takes the ConfigurationLock, which
>>     might be problematic for the error handler. I suppose the error
>>     handler could potentially deadlock if its thread already holds
>>     the lock. Unsure how to resolve this, because skipping to take
>>     the lock means that we might crash due to another thread changing
>>     the configuration as we read it.
>>
>>     Thanks,
>>     Marcus
>>
>>>>
>>>>         The logging configuration is now printed in each hs_err
>>>>         file. The output is the same as you would see from
>>>>         -Xlog:logging=trace and it is obtained from
>>>>         LogConfiguration::describe().
>>>>
>>>>         Below is a sample of the hs_err contents. The Logging info
>>>>         is printed after VM Arguments and Whitebox, and before
>>>>         Environment Variables.
>>>>
>>>>         VM Arguments:
>>>>         java_command: Kaboom
>>>>         java_class_path (initial): .
>>>>         Launcher Type: SUN_STANDARD
>>>>
>>>>         Logging:
>>>>         Available log levels: off, trace, debug, info, warning, error
>>>>         Available log decorators: time (t), uptime (u), timemillis
>>>>         (tm), uptimemillis (um), timenanos (tn), uptimenanos (un),
>>>>         hostname (hn), pid (p), tid (ti), level (l), tags (tg)
>>>>         Available log tags: alloc, age, barrier, biasedlocking,
>>>>         bot, census, classhisto, classresolve, classinit,
>>>>         classload, classloaderdata, classunload, classpath,
>>>>         compaction, cpu, cset, defaultmethods, ergo, exceptions,
>>>>         exit, freelist, gc, heap, humongous, ihop, itables, jni,
>>>>         liveness, logging, marking, metaspace, modules,
>>>>         monitorinflation, os, phases, plab, promotion, preorder,
>>>>         protectiondomain, ref, refine, region, remset, safepoint,
>>>>         safepointcleanup, scavenge, scrub, stacktrace, start,
>>>>         startuptime, state, stats, stringdedup, stringtable,
>>>>         survivor, sweep, task, thread, tlab, time,
>>>>         verboseverification, verify, vmoperation, vtables
>>>>         Log output configuration:
>>>>         #0: stdout all=off uptime,level,tags,
>>>>         #1: stderr all=warning uptime,level,tags,
>>>>
>>>>         Environment Variables:
>>>>         JAVA_HOME=/scratch/mockner/UL/8151526/build/linux-x86_64-normal-server-fastdebug/images/jdk
>>>>         PATH=/home/mockner/tools/webrev:/bin:/usr/bin:/usr/local/bin:/usr/sbin:/home/mockner/bin:/home/mockner/linux/bin
>>>>         SHELL=/bin/bash
>>>>         OS=Linux
>>>>
>>>>
>>>
>>
>
>