Extend Composite Logger log functions to have built in buffer

[GAURAVRAMRAKHYANI]

Extend Composite Logger functions to have built in buffer. This will help in combining multiple messages in single log and hence decreasing number of logs and hence time loss due to telemetry throttling is decreased.

A new optional parameter is added in log functions. The data type of the parameter is enum whose values can be true, flush and false. The default value is false.

If the buffer is true, keep appending to built-in variable.
The buffer may be flushed to the log in the very last message meant to be part of the concatenation.
If it's false, write whatever is in memory, clear it out, and also separately write the new message that came in.

The buffer line separator is used to separate different messages in the same buffer - "\n|\t".

There is common buffer for different log levels i.e., error, warning, debug and verbose. This is simpler design than having separate buffers for each log level. The issue with having single buffer for all log levels is that if log function with warning level is called 3 times with different messages with buffer=true and then log function with error level is called with buffer=flush then all the 4 messages will be written with error level because there is single buffer for all log levels. The current use cases of decreasing number of logs by combining multiple messages to single log can be achievable with single buffer for all log levels.

If required later, the design can be expanded to have separate buffers each for error, warning, debug and verbose.

Manual testing done:
Tested the different sequences of logging messages with the buffer value true, false and flush. Tested following scenarios with all log levels i.e. error, warning, debug and verbose:
(a) When log function is called 2 times with buffer=true and third time with buffer=flush, then the three logs are combined to single log.
(b) When log function is called with buffer=false then the message is logged.
(c) When log function is called with buffer=true followed by log function with buffer=false then the message with buffer=true is logged first and then the message with buffer=false is logged as a separate log.

Tested the scenarios with number of characters in message exceed the limit of maximum characters.
(a) If log function is called with buffer=true and then a new log function is called with buffer=flush and if sum of characters of both the messages exceeds the limit then both messages are logged separately.

[codecov]

Codecov Report

Merging #213 (921719b) into master (37d1596) will increase coverage by 0.04%.
The diff coverage is 97.46%.

@@            Coverage Diff             @@
##           master     #213      +/-   ##
==========================================
+ Coverage   90.34%   90.39%   +0.04%     
==========================================
  Files          90       90              
  Lines       14735    14810      +75     
==========================================
+ Hits        13312    13387      +75     
  Misses       1423     1423              

Flag	Coverage Δ
python27	90.39% <97.46%> (+0.04%)	⬆️
python39	90.39% <97.46%> (+0.04%)	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Files	Coverage Δ
src/core/src/bootstrap/Constants.py	98.66% <100.00%> (+0.02%)	⬆️
src/core/src/service_interfaces/TelemetryWriter.py	77.16% <100.00%> (+2.54%)	⬆️
src/core/tests/Test_TelemetryWriter.py	97.48% <100.00%> (+1.12%)	⬆️
src/core/src/local_loggers/CompositeLogger.py	81.53% <50.00%> (ø)

[kjohn-msft]

After some thought on this, I’m refining the last guidance on this PR to:

• Keep separation of concerns
  o CompositeLogger does not need to know about buffering except to the extent that it needs to pass it through.
  o TelemetryWriter needs to know about buffering because it’s an implementation detail it needs to worry about.
• Keep it simple – what’s the minimally-invasive change in TelemetryWriter needed? (see detail)
• Corner case – there’s a message level change case that wasn’t considered (assume calling code is buggy for robustness in implementation).

In detail:

• Constants
  o The only constant here will be BufferMessage (as it’s used in multiple classes).
  o Internal constants should be left within respective classes where possible to avoid main Constants bloat.
• CompositeLogger needs to pass through ‘Buffer’ to TelemetryWriter in 2 functions (change in CL restricted to pass through – 2 incoming function signatures, 2 outbound function calls):
  o log
  o log_debug
  o log_error, log_warning shouldn’t use buffering – no change here with default buffer parameter on log.
  o log_verbose doesn’t write to telemetry.
• TelemetryWriter needs to implement a new function:
  o write_event_with_buffer(, buffer_msg)
   This will internally abstract buffer functionality – this is the bulk of the change, neatly isolated and abstracted.
  • Constants / Variables (using correct const casing where const --):
  o (string) telemetry_buffer_store
  o (Constants.TelemetryEventLevel) last_telemetry_event_level
  o (string, const) telemetry_buffer_delimiter
  • buffer_msg == true and (last_telemetry_event_level == current or last_telemetry_event_level == None)
  o append delimiter + msg to internal buffer.
  • buffer_msg == false or (last_telemetry_event_level != current)
  o append latest message to buffer
  o flush buffer
  • buffer_msg == flush
  o flush buffer. Reset last_telemetry_event_level
   It will call write_event internally as needed (no change on write-event).
  o TelemetryWriter will continue to internally take care of wrapping, etc. There’s no need to worry about buffer overrun.
• Unit tests
  o Unit tests can focus heavily on write_event_with_buffer in TelemetryWriter with basic coverage beyond that in CompositeLogger UTs.

Things to remove from PR to strip out unnecessary complexity:

• Other constants like message level introduced to constants that were an indication of conflict between CompositeLogger and TelemetryWriter.
• Simplify CompositeLogger
  o It mustn’t buffer, should write to disk immediately. TelemetryWriter should where appropriate.
  o All the complexity around new message levels and mappings can all be removed.
  o Duplication of message length cuts, etc. is unnecessary as it’s already fully handled in TW.

[kjohn-msft]

Tentative approval on test coverage with product code as in this iteration.

[rane-rajasi]

Left one question inline. Outside of that, changes look good