RFR: 8141211: Convert TraceExceptions to Unified Logging

[Marcus Larsson]

Hi,


On 2015-12-17 09:41, 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.

Support for multi line logging was a stretch goal of the UL project that 
was never implemented. I think it might be a good feature to have, given 
that there is a lot of logging requiring such functionality. Regardless, 
having this discussion is good, because I think we need to work out the 
details of how it should work. For example, should each line in a 
multi-line message be decorated? Do we write anything special to signify 
that these lines are tied together?

The current implementation relies on the OS to do proper synchronization 
of the streams for the printf calls, which should guarantee that each 
line will be written atomically. Introducing a lock will be necessary 
for multi-line logging, but perhaps it won't be too bad if we use light 
weight locks very fine grained around the printfs. If we measure an 
increased cost for this, it should probably be weighed against the 
benefit for the use cases requiring it.

Regards,
Marcus

>
> Bengt
>
>>
>> Thanks,
>> Coleen
>>>
>>> — John
>>
>