RFR: 8151526: Print -Xlog configuration in the hs_err_pid file
Marcus Larsson
marcus.larsson at oracle.com
Tue Apr 12 12:46:21 UTC 2016
Hi Max,
On 04/11/2016 07:36 PM, Max Ockner wrote:
> Hello again,
>
> I have looked into this and I see a possible workaround to the issue
> raised by Marcus:
>
> 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.
>
>
> My proposed solution is this:
>
> If the ConfigurationLock is held by another thread during the crash,
> then I think we could print "Log configuration can not be accessed
> because ConfigurationLock is currently held by another thread" or
> something similar. If the ConfigurationLock can be taken by the
> current thread, then print the configuration.
>
> We can accomplish this as follows:
>
> In *logConfiguration.cpp*: Create a ConfigurationLockMaybe class
> extending ConfigurationLock.
>
> class ConfigurationLockMaybe : ConfigurationLock {
> private:
> bool _success;
> public:
> ConfigurationLockMaybe() {
> if (_semaphore.trywait()){_success = true;}
> }
> ~ConfigurationLock() {
> if(_success){_semaphore.signal();}
> }
> bool has_lock(){return _success;}
> };
>
> _semaphore is a static var in ConfigurationLock, so the same copy is
> accessed in child classes.
>
> Another method LogConfiguration::describe_on_crash(outputStream* out)
> can use ConfigurationLockMaybe to attempt to print the configuration.
>
> In *vmError.cpp*: Replace LogConfiguration::describe with
> LogConfiguration::describe_on_crash.
Sounds good to me.
ConfigurationLockMaybe sounds a bit weird but I don't have a better
suggestion.
Thanks,
Marcus
>
> Max
>
> On 4/11/2016 10:23 AM, Max Ockner wrote:
>> I missed this before. I'm going to investigate.
>> Max
>>
>> On 4/11/2016 4:19 AM, Marcus Larsson wrote:
>>>
>>>
>>> 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
>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>>
>>>
>>
>
More information about the hotspot-runtime-dev
mailing list