WL#10942: Logging services: force-print certain non-error messages to error log

Affects: Server-8.0   —   Status: Complete

There has been a long-standing issue where messages sent through error logging 
had two particles, a severity and a textual message, and items were filtered on 
severity (e.g. using --log-error-verbosity). In other words, the severity when 
chosen at the time of message submission would control both the label ("error", 
"warning", "note") the message would be printed with AND whether the message 
would be printed at all (severity vs verbosity).

This meant that with a low verbosity ("errors only"), important system messages 
that were not really errors ("starting", "ready, listening on port ...") had to 
be tagged as errors to make sure they would be shown, which would lead to some 
awkward, confusing message of the "error: success" form. 

Goal of this WL is to introduce a new severity and a label "System" for the
system messages and prevent these system messages from discarding using
the verbosity filtering.
Func-Req 1 Force-print messages must be written to the error log as
           [System] instead of [Error], [Warning], [Note]

	   In the "classic" MySQL error log, we have been using labels
           of "Note", "Warning", and "ERROR".

           This will remain the case for all events except those
           listed; events that are  "force-printed" will have their
           labels as "System".


Func-Req 2 It should not be possible for the user or DBA to influence
           [System] and [Error] messages. I.e. they will be printed
           regardless of verbosity and cannot be suppressed.
           (Some can indirectly be influenced by SQL mode).

           Log messages with [Error] label are printed regardless of
           verbosity and cannot be suppressed now.
           Even log messages with [System] label will be printed
           regardless of verbosity and not allowed to suppress.

Func-Req 3 [System] messages will be mapped to Linux Syslog and Windows
           Event log as we do for [Note] messages today.

	   While using system facilities such as Linux SysLog, Windows
           EventLog and etc, we are limited by the supported severities.
           Hence the [System] label is mapped to the Note label in
           linux Syslog and Windows event log.


Syslog:
* https://en.wikipedia.org/wiki/Syslog

Windows Event Log levels:
* https://msdn.microsoft.com/en-us/library/office/ff604025(v=office.14).aspx
INTERFACES

I-1  SQL syntax

No change.

I-2  INSTRUMENTATION

No change.

I-3  ERROR AND WARNINGS

No change (but see I-10)

I-4  UPGRADE

No change.

I-5  COMMERCIAL PLUGINS

No change.

I-6  REPLICATION

Certain messages from the replication subsystem will be force-printed, and 
therefore will appear with variant labels (cf. I-10) in certain log types.
(see below for list of messages)

I-7  XPROTOCOL

No change.

I-8  PROTOCOLS

No change.

I-9  SECURITY

No change.

I-10  LOG FILES

In log-writers that support custom labels, the labels of force-printed messages 
may appear with label "System". In the context of this WL, this will 
specifically be the case for the default log-sink, i.e. the traditional MySQL 
error log file.

I-11  MYSQL CLIENTS

No change.

I-12  AUTH

No change.

I-13  GLOBALIZATION

No change.

I-14  CONFIGURATION

No change.

I-15  FILE FORMATS

No change.

I-16  PLUGINS/APIS

Log-service API's label_from_prio() now shall leave decisions about using
custom label "System" to individual log-sinks. This is a refinement only with 
respect to the new log-sinks added in version 8. (cf. I-10)

I-17  MYSQL ADMIN/UTIL/OTHER PROGRAMS

No change.

I-18  STORAGE ENGINES

No change.

I-19  DATATYPES

No change.



MESSAGES

The list of messages under consideration for force-printing at this time:

ER_STARTING_AS
ER_STARTUP

ER_XA_STARTING_RECOVERY
ER_XA_RECOVERY_DONE

ER_NORMAL_SHUTDOWN
ER_SHUTDOWN_COMPLETE

ER_RPL_SLAVE_CONNECTED_TO_MASTER_REPLICATION_STARTED
ER_RPL_SLAVE_CONNECTED_TO_MASTER_REPLICATION_RESUMED

ER_SLAVE_CHANGE_MASTER_TO_EXECUTED

ER_GTID_PURGED_WAS_CHANGED
ER_GTID_EXECUTED_WAS_CHANGED

ER_CHANGED_GTID_MODE

ER_RPL_SLAVE_DUMP_THREAD_KILLED_BY_MASTER



CONSIDERATIONS

I - LABELS: NAMES

While we can print whatever labels we please in our textual logs, we are limited 
to supported severities while using system facilities such as syslog, Windows 
EventLog, etc. It would therefore serve us well to print the messages in 
question with a label of "Note" or equivalent (e.g. "Information" in 
syslog/EventLog), rather than to use custom labels ("System") that will print
correctly in some logs, but not in others.

II - LABELS: Default log-sink.

In the default log-sink, force-printed error messages gets the "System" label.
New severity "SYSTEM_LEVEL" is introduced in "enum loglevel" for force-printed
(or system) messages. 


III - CAVEATS

This mechanism affects message filtering within the server context ("Verbosity 
is set to low, and this is a [System], but print it anyway!"), i.e. what gets 
forwarded to log-writer services. For file-writers, the assumption is usually 
that if we pass a log-event, at least some of its particles (e.g. the 
message string) are written to its log. Where we forward to OS subsystems 
though, the configuration of those subsystems also applies; if we "force-print" 
a error message, we can make sure it arrives in the syslog log-writer service 
which will pass it on to the OS' syslog facility. We can not however prevent a 
syslogging daemon configured to do so from throwing away all [Note]s (or logging 
them to a different destination than [Error]s are). This is a potentially docs-
worthy caveat; it is not however a bug: suppose an environment where [Error]s 
raise an alarm in monitoring -- while "started and listening on port X" may be 
important, "print always" information, it's not worth waking the admin over. :)



INTERFACE

The old behaviour of the severity and the label being directly related is 
retained as a default, as suggested by the principle of the least surprise, by 
minimum invasive change, and by minimum typing required by other engineers. :)


- New severity (or error level) "SYSTEM_LEVEL" is added to the        
  enum loglevel.                                                      
                                                                      
- Severity of "SYSTEM_LEVEL" is higher than the "ERROR_LEVEL".        
                                                                      
- Use "SYSTEM_LEVEL" for the list of calls given in the WL ticket.    
                                                                      
- sinks can use the value returned by label_from_prio() ("System",    
  "Error", "Warning", "Note") directly.                               
                                                                      
- Sinks(e.g. Linux SysLog and Windows event log) which does not       
  support custom labels "SYSTEM_LEVEL" is mapped to the               
  "INFORMATION_LEVEL".                                                
                                                                      
- Behavior with respect to --log-error-verbosity remains the same.    
  Error logs with severity greater than WARNING are always printed.