RFR: 8145934: Make ttyLocker equivalent for Unified Logging framework

[Marcus Larsson]

Hi again,

Alternative version where a LogMessage automatically writes its messages 
when it goes out of scope:
http://cr.openjdk.java.net/~mlarsson/8145934/webrev.alt/

I still prefer the first patch though, where messages are neither tied 
to a particular log, nor automatically written when they go out of 
scope. Like I've said, the explicit write line makes it easier to read 
the code.

For comparison I've updated the first suggestion with the guarantee for 
unwritten messages, as well as cleaning it up a bit by moving the 
implementation to the .cpp rather than the .hpp.
Full webrev: http://cr.openjdk.java.net/~mlarsson/8145934/webrev.01/
Incremental: http://cr.openjdk.java.net/~mlarsson/8145934/webrev.00-01/

Let me know what you think.

Thanks,
Marcus

On 02/11/2016 04:29 PM, Marcus Larsson wrote:
> Hi,
>
> On 02/10/2016 11:43 PM, John Rose wrote:
>> Thanks for taking this on.
>
> Thanks for looking at it!
>
>>
>> To be an adequate substitute for ttyLocker it needs to
>> support block structure via the RAII pattern.  Otherwise
>> the use cases are verbose enough to be a burden on
>> programmers.
>>
>> This is easy, I think:  Give LogMessage a constructor
>> which takes a reference to the corresponding LogHandle.
>> Have the LogMessage destructor call log.write(*this).
>
> Having automatic writing of the messages when they go out of scope 
> would be convenient I guess. The idea with the current and more 
> verbose API is to make it clear that the log message is just some 
> in-memory buffer that can be used to prepare a multi-part message, 
> which is sent explicitly to the intended log when ready. It makes it 
> very obvious how the different components interact, at the cost of 
> perhaps unnecessary verbosity. Having it automatically written makes 
> it less verbose, but also a bit cryptic, IMHO.
>
>>
>> (BTW, as written it allows accidentally dropped writes,
>> which is bad:  We'll never find all those bugs.  That's
>> the burden of a rough-edged API, especially when it is
>> turned off most of the time.)
>
> We could add an assert/guarantee in an attempt to prevent this.
>
>>
>> If necessary or for flexibility, allow the LogMessage
>> constructor an optional boolean to say "don't write
>> automatically".  Also, allow a "reset" method to
>> cancel any buffered writing.  So the default is to
>> perform the write at the end of the block (if there
>> is anything to write), but it can be turned off
>> explicitly.
>>
>> Giving the LogMessage a clear linkage to a LogHandle
>> allows the LogMessage to be a simple delegate for
>> the LogHandle itself.  This allows the user to ignore
>> the LogHandle and work with the LogMessage as
>> if it were the LogHandle.  That seems preferable
>> to requiring split attention to both objects.
>>
>> Given this simplification, the name LogMessage
>> could be changed to BufferedLogHandle, LogBuffer,
>> ScopedLog, etc., to emphasize that the thing is
>> really a channel to some log, but with an extra
>> bit of buffering to control.
>
> I still think the LogMessage name makes sense. BufferedLogHandle and 
> the likes give the impression that it's a LogHandle with some internal 
> buffering for the sake of performance, which actually the opposite of 
> it's intention. This class should only be used when it is important 
> that the multi-line message isn't interleaved by other messages. I 
> still expect the majority of the logging throughout the VM to still 
> use the regular (and faster) LogHandle and/or log macros.
>
>>
>> To amend your example use case:
>>
>>      // example buffered log messages (proposed)
>>      LogHandle(logging) log;
>>      if (log.is_debug()) {
>>        ResourceMark rm;
>>        LogMessage msg;
>>        msg.debug("debug message");
>>        msg.trace("additional trace information");
>>        log.write(msg);
>>      }
>>
>> Either this:
>>
>>      // example buffered log messages (amended #1)
>>      LogHandle(logging) log;
>>      if (log.is_debug()) {
>>        ResourceMark rm;
>>        LogBuffer buf(log);
>>        buf.debug("debug message");
>>        buf.trace("additional trace information");
>>      }
>>
>> Or this:
>>
>>      // example buffered log messages (amended #2)
>>      { LogBuffer(logging) log;
>>        if (log.is_debug()) {
>>          ResourceMark rm;
>>          log.debug("debug message");
>>          log.trace("additional trace information");
>>        }
>>      }
>>
>> The second is probably preferable, since it encourages the
>> logging logic to be modularized into a single block, and
>> because it reduces the changes for error that might occur
>> from having two similar names (log/msg or log/buf).
>
> The second case is more compact, which is always a good thing when it 
> comes to logging. For the more involved scenarios where there are 
> multiple messages being sent, I usually assume (perhaps incorrectly) 
> that a LogHandle is used throughout the scope of such 
> scenarios/functions, for the sake of compactness and consistency (not 
> having to specify log tags in more than one place). In those cases 
> there would already be a LogHandle that could be used for testing 
> levels and such. With messages tied to a particular output like you 
> suggest, it does however make sense to allow level testing functions 
> on the message instances as well.
>
> I'll prepare another patch with your suggestions and we'll see how it 
> turns out.
>
> Thanks,
> Marcus
>
>>
>> The second usage requires the LogBuffer constructor
>> to be lazy:  It must delay internal memory allocation
>> until the first output operation.
>>
>> — John
>