RFR: 8141211: Convert TraceExceptions to Unified Logging

[Staffan Larsen]

> On 18 dec. 2015, at 14:06, David Holmes <david.holmes at oracle.com> wrote:
> 
> On 18/12/2015 7:14 PM, Bengt Rutisson wrote:
>> 
>> 
>> On 2015-12-18 06:44, David Holmes wrote:
>>> On 17/12/2015 6:41 PM, Bengt Rutisson wrote:
>>>> On 2015-12-16 22:43, Coleen Phillimore wrote:
>>>>> On 12/16/15 4:01 PM, John Rose wrote:
>>>>>> On Dec 15, 2015, at 12:26 PM, Rachel Protacio
>>>>>> <rachel.protacio at oracle.com> wrote:
>>>>>>> - each incident of ttyLocker that involved separate logging lines
>>>>>>> for the same message have been consolidated to one line
>>>>>>> - each incident of ttyLocker that involved separate print statements
>>>>>>> to one logging line has been changed to write to a buffer first,
>>>>>>> then print the entire line at once to the log stream
>>>>>> This is a strong argument for putting such functionality into the UL
>>>>>> framework,
>>>>>> instead of giving developers the unfortunate choice of either (a)
>>>>>> doing it right
>>>>>> with a bunch of random logic (Rachel's choice here) or (b) sweeping
>>>>>> it under
>>>>>> the carpet by breaking up a multi-part message into several log
>>>>>> messages.
>>>>>> 
>>>>>> We need to admit this is the Achilles Heel of logging as normally
>>>>>> conceived
>>>>>> (especially for very long multi-part messages like disassembler
>>>>>> output,
>>>>>> backtraces, or compilation logs), and just fix it in the UL frameowrk.
>>>>> 
>>>>> Yes, I agree.  We should file a high priority RFE against UL for this
>>>>> if one isn't filed already.  The runtime only uses ttyLocker (as far
>>>>> as I found) for TraceExceptions but the compiler uses it more often to
>>>>> aggregate messages.   The lack of a locking mechanism seems to be one
>>>>> of the factors blocking the compiler group adoption of this feature.
>>>>> And will block more complex runtime logging conversions.
>>>>> 
>>>>> So what do people vote that we do?  Should we log the messages
>>>>> separately until this is fixed?  I agreed with making these logs one
>>>>> line because even though they wrap, they weren't that long. It would
>>>>> be nice to be able to do the conversion work to UL concurrently while
>>>>> finding problems in the framework, and not be stuck.
>>>> 
>>>> From my point of view it would be very unfortunate to require all
>>>> logging to take an extra lock. If the multiline support can be
>>>> implemented in the UL framework without any extra cost for "normal"
>>>> logging I would be fine with it. But if it would slow down the normal
>>>> logging, which I assume would be the case if we require an extra lock,
>>>> then I would prefer to push the responsibility up to the users of the UL
>>>> framework to synchronize properly.
>>> 
>>> How would users of the framework synchronize access to a shared
>>> resource where some of the users of the resource are not party to the
>>> synchronization process? AFAICS the synchronization has to be at the
>>> resource-level.
>> 
>> I think it depends on what problem we are trying to solve. In most cases
>> I have seen so far it would be fine for two different activities to log
>> their output interleaved. If for example the compiler would log
>> something during a GC I wouldn't see that as a serious problem. It is
> 
> I don't really agree but I see where you are coming from.
> 
>> easy for a reader of the log file (human or machine) to sort out the
>> logging since logging is never interleaved on the same line. And there
> 
> Actually ... we have seen Trace output "corrupted" somehow where lines are combined. This happened with some CDS-related tests earlier this year with TraceClassLoading - we had to relax the pattern so the corrupted lines would be accepted. Never did get to the bottom of it.

Have you seen this happen with UL as well?

> 
> Cheers,
> David
> 
>> is also the possibility for a user to pipe the logging to different
>> files based on their tags.
>> 
>> The problem I thought this email thread was about was when the same type
>> of logging is done from multiple threads. Having multiple threads log
>> multiple lines of similar data at the same time will be very hard to
>> sort out after-the-fact in the log file. But since it is the same
>> subsystem that does the logging that subsystem could introduce its own
>> synchronization. It would of course not be synchronized with all other
>> users of the UL framework, but I don't think that is such a big problem.
>> 
>> Having said that, I am not against introducing multi-line logging
>> support in the UL framework. I just would like to make sure that it does
>> not come with a too high cost for all the use cases where the
>> synchronization is not a problem.
>> 
>> Using a buffered logger, as is being discussed now, would probably be a
>> good solution since it wouldn't introduce a cost for the other logging.
>> 
>> Bengt
>> 
>> 
>> 
>>> 
>>> David
>>> -----
>>> 
>>>> Bengt
>>>> 
>>>>> 
>>>>> Thanks,
>>>>> Coleen
>>>>>> 
>>>>>> — John

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20151218/5f0f0344/attachment-0001.html>