From 9af8bca495c1704d7ce010939c7e54df7bfdef71 Mon Sep 17 00:00:00 2001 From: Peter Andersson Date: Mon, 11 Jun 2018 22:48:25 +0200 Subject: [logger] Update handler documentation --- lib/kernel/doc/src/logger_chapter.xml | 243 +++++++++++++++++-------------- lib/kernel/doc/src/logger_disk_log_h.xml | 123 ++++++++-------- lib/kernel/doc/src/logger_std_h.xml | 71 ++++----- 3 files changed, 234 insertions(+), 203 deletions(-) (limited to 'lib/kernel/doc/src') diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml index f7df0a3e6e..5eab48f63e 100644 --- a/lib/kernel/doc/src/logger_chapter.xml +++ b/lib/kernel/doc/src/logger_chapter.xml @@ -1103,184 +1103,205 @@ do_log(Fd, LogEvent, #{formatter := {FModule, FConfig}}) ->
Protecting the Handler from Overload -

In order for the built-in handlers to survive, and stay responsive, - during periods of high load (i.e. when huge numbers of incoming - log requests must be handled), a mechanism for overload protection - has been implemented in the - logger_std_h - and logger_disk_log_h - handler. The mechanism, used by both handlers, works - as follows:

+

The default handlers, + logger_std_h and + logger_disk_log_h, feature an overload protection + mechanism, which makes it possible for the handlers to survive, + and stay responsive, during periods of high load (i.e. when huge + numbers of incoming log requests must be handled). + The mechanism works as follows:

Message Queue Length

The handler process keeps track of the length of its message - queue and reacts in different ways depending on the current status. - The purpose is to keep the handler in, or (as quickly as possible), - get the handler into, a state where it can keep up with the pace - of incoming log requests. The memory usage of the handler must never - keep growing larger and larger, since that would eventually cause the - handler to crash. Three thresholds with associated actions have been - defined:

+ queue and takes some form of action when the current length exceeds a + configurable threshold. The purpose is to keep the handler in, or to + as quickly as possible get the handler into, a state where it can + keep up with the pace of incoming log events. The memory use of the + handler must never grow larger and larger, since that will eventually + cause the handler to crash. These three thresholds, with associated + actions, exist:

- toggle_sync_qlen + sync_mode_qlen -

The default value of this level is 10 messages, - and as long as the length of the message queue is lower, all log - requests are handled asynchronously. This simply means that the - process sending the log request (by calling a log function in the - Logger API) does not wait for a response from the handler but - continues executing immediately after the request (i.e. it will not - be affected by the time it takes the handler to print to the log - device). If the message queue grows larger than this value, however, - the handler starts handling the log requests synchronously instead, - meaning the process sending the request will have to wait for a - response. When the handler manages to reduce the message queue to a - level below the toggle_sync_qlen threshold, asynchronous +

As long as the length of the message queue is lower than this + value, all log events are handled asynchronously. This means that + the process sending the log event, by calling a log function in the + Logger API, does not wait for a response from the handler, but + continues executing immediately after the event is sent (that is, it + is not affected by the time it takes the handler to print the event + to the log device). If the message queue grows larger than this value, + the handler starts handling log events synchronously instead, + meaning that the process sending the event, must wait for a + response. When the handler reduces the message queue to a + level below the sync_mode_qlen threshold, asynchronous operation is resumed. The switch from asynchronous to synchronous - mode will force the logging tempo of few busy senders to slow down, - but cannot protect the handler sufficiently in situations of many - concurrent senders.

+ mode can slow down the logging tempo of one, or a few, busy senders, + but cannot protect the handler sufficiently in a situation of many + busy concurrent senders.

+

Default value of the threshold: 10 messages.

 - drop_new_reqs_qlen + drop_mode_qlen -

When the message queue has grown larger than this threshold, which - defaults to 200 messages, the handler switches to a mode in - which it drops any new requests being made. Dropping a message in - this state means that the log function never actually sends a message - to the handler. The log call simply returns without an action. When - the length of the message queue has been reduced to a level below this - threshold, synchronous or asynchronous request handling mode is - resumed.

+

When the message queue grows larger than this threshold, the + handler switches to a mode in which it drops all new events that + senders want to send. Dropping an event in ths mode, means that the + log function never sends a message to the handler, but returns + without taking any action. The handler keeps logging events already + in the message queue, and when the length of the message queue is + reduced to a level below the threshold, synchronous or asynchronous + mode is resumed. Note that when the handler activates, or deactivates, + drop mode, information about it is printed to the log.

+

Default value of the threshold: 200 messages.

 - flush_reqs_qlen + flush_qlen -

Above this threshold, which defaults to 1000 messages, a - flush operation takes place, in which all messages buffered in the - process mailbox get deleted without any logging actually taking - place. (Processes waiting for a response from a synchronous log request - will receive a reply indicating that the request has been dropped).

+

If the length of the message queue grows larger than this threshold, + a flush (delete) operation takes place. To flush events, the handler receives + the messages in the process mailbox in a loop without logging (that is, the + handler deletes the events). Processes waiting for a response from a + synchronous log request will receive a reply from the handler indicating + that the request has been dropped. The handler process will set its own priority + to high during the flush loop to make sure that no new events come in + during the operation. Note that after the flush operation is performed, + the handler prints information in the log about how many events have been + deleted

+

Default value of the threshold: 1000 messages.

For the overload protection algorithm to work properly, it is required that:

-

toggle_sync_qlen =< drop_new_reqs_qlen =< flush_reqs_qlen

+

sync_mode_qlen =< drop_mode_qlen =< flush_qlen

and that:

-

drop_new_reqs_qlen > 1

+

drop_mode_qlen > 1

-

If toggle_sync_qlen is set to 0, the handler will handle all - requests synchronously. Setting the value of toggle_sync_qlen to the same - as drop_new_reqs_qlen, disables the synchronous mode. Likewise, setting - the value of drop_new_reqs_qlen to the same as flush_reqs_qlen, - disables the drop mode.

+

To disable certain modes, do the following:

+ + If sync_mode_qlen is set to 0, all log events are handled + synchronously. That is, asynchronous logging is disabled. + If sync_mode_qlen is set to the same value as + drop_mode_qlen, synchronous mode is disabled. That is, the handler + always runs in asychronous mode, unless dropping or flushing is invoked. + If drop_mode_qlen is set to the same value as flush_qlen, + drop mode is disabled and can never occur. +

During high load scenarios, the length of the handler message queue rarely grows in a linear and predictable way. Instead, whenever the handler process gets scheduled in, it can have an almost arbitrary number of messages waiting in the mailbox. It's for this reason that the overload - protection mechanism is focused on acting quickly and quite drastically - (such as immediately dropping or flushing messages) as soon as a large - queue length is detected.

- -

The thresholds listed above may be modified by the user if, e.g, a handler - shouldn't drop or flush messages unless the message queue length grows - extremely large. (The handler must be allowed to use large amounts of memory - under such circumstances however). Another example of when the user might want - to change the settings is if, for performance reasons, the logging processes must - never get blocked by synchronous log requests, while dropping or flushing requests - is perfectly acceptable (since it doesn't affect the performance of the - loggers).

+ protection mechanism is focused on acting quickly, and quite drastically, + such as immediately dropping or flushing messages, when a large queue length + is detected.

+ +

The values of the previously listed thresholds can be specified by the user. + This way, a handler can be configured to, for example, not drop or flush + messages unless the message queue length of the handler process grows extremely + large. Note that large amounts of memory can be required for the node under such + circumstances. Another example of user configuration is when, for performance + reasons, the logging processes must never get blocked by synchronous log requests. + It's possible, perhaps, that dropping or flushing events is still acceptable (since + it does not affect the performance of the processes sending the log events).

A configuration example:

logger:add_handler(my_standard_h, logger_std_h, #{config => #{type => {file,"./system_info.log"}, - toggle_sync_qlen => 100, - drop_new_reqs_qlen => 1000, - flush_reqs_qlen => 2000}}). + sync_mode_qlen => 100, + drop_mode_qlen => 1000, + flush_qlen => 2000}}).
Controlling Bursts of Log Requests -

A potential problem with large bursts of log requests, is that log files - may get full or wrapped too quickly (in the latter case overwriting - previously logged data that could be of great importance). For this reason, - both built-in handlers offer the possibility to set a maximum level of how - many requests to process with a certain time frame. With this burst control - feature enabled, the handler will take care of bursts of log requests - without choking log files, or the terminal, with massive amounts of - printouts. These are the configuration parameters:

+

Large bursts of log events (that is, many events received by the handler + under a short period of time), can potentially cause problems, such as:

+ + Log files grow very large, very quickly. + Circular logs wrap too quickly so that important data gets overwritten. + Write buffers grow large, which slows down file sync operations. + + +

For this reason, both built-in handlers offer the possibility to specify the + maximum number of events to be handled within a certain time frame. + With this burst control feature enabled, the handler can avoid choking the log with + massive amounts of printouts. These are the configuration parameters:

- enable_burst_limit + burst_limit_enable -

This is set to true by default. The value false - disables the burst control feature.

+

Value true enables burst control and false disables it.

+

Defaults to true.

 - burst_limit_size + burst_limit_max_count -

This is how many requests should be processed within the - burst_window_time time frame. After this maximum has been - reached, successive requests will be dropped until the end of the - time frame. The default value is 500 messages.

+

This is the maximum number of events to handle within a + burst_limit_window_time time frame. After the limit has been + reached, successive events get dropped until the end of the time frame.

+

Defaults to 500 events.

 - burst_window_time + burst_limit_window_time -

The default window is 1000 milliseconds long.

+

See the previous description of burst_limit_window_time.

+

Defaults to 1000 milliseconds.

A configuration example:

logger:add_handler(my_disk_log_h, logger_disk_log_h, - #{disk_log_opts => - #{file => "./my_disk_log"}, - config => - #{burst_limit_size => 10, - burst_window_time => 500}}). + #{config => + #{file => "./my_disk_log", + burst_limit_enable => true, + burst_limit_max_count => 20, + burst_limit_window_time => 500}}).
- Terminating a Large Handler -

A handler process may grow large even if it can manage peaks of high load - without crashing. The overload protection mechanism includes user configurable - levels for a maximum allowed message queue length and maximum allowed memory - usage. This feature is disabled by default, but can be switched on by means - of the following configuration parameters:

- + Terminating an Overloaded Handler +

It is possible that a handler, even if it can successfully manage peaks + of high load without crashing, can build up a large message queue, or use a + large amount of memory. The overload protection mechanism includes an + automatic termination and restart feature for the purpose of guaranteeing + that a handler does not grow out of bounds. The feature can be configured + with the following parameters:

- enable_kill_overloaded + overload_kill_enable -

This is set to false by default. The value true - enables the feature.

+

Value true enables the feature and false disables it.

+

Defaults to false.

 - handler_overloaded_qlen + overload_kill_qlen

This is the maximum allowed queue length. If the mailbox grows larger than this, the handler process gets terminated.

+

Defaults to 20000 messages.

 - handler_overloaded_mem + overload_kill_mem_size -

This is the maximum allowed memory usage of the handler process. If - the handler grows any larger, the process gets terminated.

+

This is the maximum memory size that the handler process is allowed to use. + If the handler grows larger than this, the process gets terminated.

+

Defaults to 3000000 bytes.

 - handler_restart_after + overload_kill_restart_after -

If the handler gets terminated because of its queue length or - memory usage, it can get automatically restarted again after a - configurable delay time. The time is specified in milliseconds - and 5000 is the default value. The value never can - also be set, which prevents a restart.

+

If the handler gets terminated, it can restart automatically after a + delay, specified in milliseconds. The value infinity can also be set, + which prevents restarts.

+

Defaults to 5000 milliseconds.

 +

If the handler process gets terminated because of overload, information about + this event is printed in the log. Information about when a restart has taken + place, and the handler is back in action, is also printed.

diff --git a/lib/kernel/doc/src/logger_disk_log_h.xml b/lib/kernel/doc/src/logger_disk_log_h.xml index 63c29cb010..c60cf14cc7 100644 --- a/lib/kernel/doc/src/logger_disk_log_h.xml +++ b/lib/kernel/doc/src/logger_disk_log_h.xml @@ -38,101 +38,110 @@

This is a handler for Logger that offers circular (wrapped) logs by using disk_log. - Multiple instances - of this handler can be added to Logger, and each instance prints to - its own disk_log file, created with the name and settings specified in - the handler configuration.

+ Multiple instances of this handler can be added to Logger, and each instance + prints to its own disk_log file, created with the name and settings specified + in the handler configuration.

The default standard handler, logger_std_h, can be - replaced by a disk_log handler at start up of the Kernel application. + replaced by a disk_log handler at startup of the Kernel application. See an example of this below.

-

The handler has an overload protection mechanism that will keep the handler - process and the Kernel application alive during a high load of log - requests. How this feature works, and how to modify the configuration, - is described in the +

The handler has an overload protection mechanism that keeps the handler + process and the Kernel application alive during high loads of log + events. How overload protection works, and how to configure it, is + described in the User's Guide .

To add a new instance of the disk_log handler, use logger:add_handler/3 - . The handler configuration argument is a map which may contain + . The handler configuration argument is a map which can contain general configuration parameters, as documented in the User's Guide - , as well as handler specific parameters.

-

The settings for the disk_log log file should be specified with the - key disk_log_opts. These settings are a subset of the disk_log - data type - dlog_option().

-

Parameters in the disk_log_opts map:

+ , and handler specific parameters. The specific data + is stored in a sub map with the key config, and can contain the + following parameters:

file - This is the full name of the disk_log log file. + +

This is the full name of the disk_log log file. The option + corresponds to the name property in the + dlog_option() + datatype.

+ type - This is the disk_log type, wrap or halt. The - default value is wrap. + +

This is the disk_log type, wrap or halt. The option + corresponds to the type property in the + dlog_option() + datatype.

+

Defaults to wrap.

+ max_no_files - This is the maximum number of files that disk_log will use - for its circular logging. The default value is 10. (The setting - has no effect on a halt log). + +

This is the maximum number of files that disk_log will use + for its circular logging. The option + corresponds to the MaxNoFiles element in the size property in the + dlog_option() + datatype.

+

Defaults to 10. (The setting has no effect on a halt log).

+ max_no_bytes - This is the maximum number of bytes that will be written to - a log file before disk_log proceeds with the next file in order (or - generates an error in case of a full halt log). The default value for - a wrap log is 1048576 bytes, and infinity for a halt - log. - -

Specific configuration for the handler (represented as a sub map) - is specified with the key config. It may contain the - following parameter:

- + +

This is the maximum number of bytes that will be written to + a log file before disk_log proceeds with the next file in order (or + generates an error in case of a full halt log). The option + corresponds to the MaxNoBytes element in the size property in the + dlog_option() + datatype.

+

Defaults to 1048576 bytes for a wrap log, and + infinity for a halt log.

+ filesync_repeat_interval -

This value (in milliseconds) specifies how often the handler will - do a disk_log sync operation in order to make sure that buffered data - gets written to disk. The handler will repeatedly attempt this - operation, but only perform it if something has actually been logged - since the last sync. The default value is 5000 milliseconds. - If no_repeat is set as value, the repeated sync operation is - disabled. The user can also call the - sync/1 - function to perform a disk_log sync.

 +

This value, in milliseconds, specifies how often the handler does + a disk_log sync operation to write buffered data to disk. The handler attempts + the operation repeatedly, but only performs a new sync if something has + actually been logged.

+

Defaults to 5000 milliseconds.

+

If no_repeat is set as value, the repeated sync operation + is disabled. The user can also call the + filesync/1 + function to perform a disk_log sync.

+ -

There are a number of other configuration parameters available, that are - to be used for customizing the overload protection behaviour. The same - parameters are used both in the standard handler and the disk_log handler, - and are documented in the +

Other configuration parameters exist, to be used for customizing + the overload protection behaviour. The same parameters are used both in the + standard handler and the disk_log handler, and are documented in the User's Guide .

Note that when changing the configuration of the handler in runtime, by calling logger:set_handler_config/2 - or logger:set_handler_config/3, the disk_log_opts - settings may not be modified.

+ or logger:set_handler_config/3, the disk_log options (file, + type, max_no_files, max_no_bytes) must not be modified.

Example of adding a disk_log handler:

logger:add_handler(my_disk_log_h, logger_disk_log_h, #{level => error, filter_default => log, - disk_log_opts => - #{file => "./my_disk_log", - type => wrap, - max_no_files => 4, - max_no_bytes => 10000}, - config => - #{filesync_repeat_interval => 1000}}). + config => #{file => "./my_disk_log", + type => wrap, + max_no_files => 4, + max_no_bytes => 10000}, + filesync_repeat_interval => 1000}}). -

In order to use the disk_log handler instead of the default standard +

To use the disk_log handler instead of the default standard handler when starting an Erlang node, change the Kernel default logger to use disk_log. Example:

erl -kernel logger '[{handler,default,logger_disk_log_h, - #{disk_log_opts => #{file => "./system_disk_log"}}}]' + #{config => #{file => "./system_disk_log"}}}]' - + Writes buffered data to disk.

Write buffered data to disk.

diff --git a/lib/kernel/doc/src/logger_std_h.xml b/lib/kernel/doc/src/logger_std_h.xml index 89e11389c5..08667ae7f9 100644 --- a/lib/kernel/doc/src/logger_std_h.xml +++ b/lib/kernel/doc/src/logger_std_h.xml @@ -38,62 +38,63 @@

This is the default handler for Logger. Multiple instances of this handler can be added to - Logger, and each instance will print logs to standard_io, + Logger, and each instance prints logs to standard_io, standard_error or to file. The default instance that starts - with Kernel is named default - which is the name to be used + with Kernel is named default, which is the name to be used for reconfiguration.

-

The handler has an overload protection mechanism that will keep the handler - process and the Kernel application alive during a high load of log - requests. How this feature works, and how to modify the configuration, - is described in the +

The handler has an overload protection mechanism that keeps the handler + process and the Kernel application alive during high loads of log + events. How overload protection works, and how to configure it, is + described in the User's Guide .

To add a new instance of the standard handler, use logger:add_handler/3 - . The handler configuration argument is a map which may contain - general configuration parameters, as documented in the + . The handler configuration argument is a map which can contain + general configuration parameters, as documented in the User's Guide - , as well as handler specific parameters. The specific parameters - are stored in a sub map with the key config. The following - keys and values may be specified:

+ , and handler specific parameters. The specific data + is stored in a sub map with the key config, and can contain the + following parameters:

type -

This will have the value standard_io, standard_error, - {file,LogFileName}, or {file,LogFileName,LogFileOpts}, - where standard_io is the default value for type. It's recommended - to not specify LogFileOpts if not absolutely necessary. The - default options used by the handler to open a file for logging are: - raw, append and delayed_write. The standard +

This has the value standard_io, standard_error, + {file,LogFileName}, or {file,LogFileName,LogFileOpts}.

+

Defaults to standard_io.

+

It is recommended to not specify LogFileOpts, unless absolutely + necessary. The default options used by the handler to open a file for logging are: + raw, append and delayed_write. Note that the standard handler does not have support for circular logging. Use the logger_disk_log_h - handler for this.

 + handler for this.

+ filesync_repeat_interval -

This value (in milliseconds) specifies how often the handler will - do a file sync operation in order to make sure that buffered data gets - written to disk. The handler will repeatedly attempt this - operation, but only perform it if something has actually been logged - since the last sync. The default value is 5000 milliseconds. - If no_repeat is set as value, the repeated file sync operation +

This value, in milliseconds, specifies how often the handler does + a file sync operation to write buffered data to disk. The handler attempts + the operation repeatedly, but only performs a new sync if something has + actually been logged.

+

Defaults to 5000 milliseconds.

+

If no_repeat is set as value, the repeated file sync operation is disabled, and it will be the operating system settings that determine how quickly or slowly data gets written to disk. The user can also call - the sync/1 - function to perform a file sync.

 + the filesync/1 + function to perform a file sync.

+ -

There are a number of other configuration parameters available, that are - to be used for customizing the overload protection behaviour. The same - parameters are used both in the standard handler and the disk_log handler, - and are documented in the +

Other configuration parameters exist, to be used for customizing + the overload protection behaviour. The same parameters are used both in the + standard handler and the disk_log handler, and are documented in the User's Guide .

-

Note that when changing the configuration of the handler in runtime, by +

Note that if changing the configuration of the handler in runtime, by calling logger:set_handler_config/2 , or logger:set_handler_config/3 , - the type parameter may not be modified.

+ the type parameter must not be modified.

Example of adding a standard handler:

logger:add_handler(my_standard_h, logger_std_h, @@ -103,9 +104,9 @@ logger:add_handler(my_standard_h, logger_std_h, #{type => {file,"./system_info.log"}, filesync_repeat_interval => 1000}}). -

In order to configure the default handler (that starts initially with +

To set the default handler (that starts initially with the Kernel application) to log to file instead of standard_io, - change the Kernel default logger to use a file. Example:

+ change the Kernel default logger configuration. Example:

erl -kernel logger '[{handler,default,logger_std_h, #{config => #{type => {file,"./log.log"}}}}]' @@ -118,7 +119,7 @@ erl -kernel logger '[{handler,default,logger_std_h, - + Writes buffered data to disk.

Write buffered data to disk.

-- cgit v1.2.3