aboutsummaryrefslogtreecommitdiffstats
path: root/lib
diff options
context:
space:
mode:
authorPeter Andersson <[email protected]>2018-04-25 21:18:08 +0200
committerSiri Hansen <[email protected]>2018-04-26 15:51:46 +0200
commitee44197422710dabe43f2f4b80d1034aae9c916f (patch)
treed22ae35199f6c27fb6d149cf21576b0647a9ec43 /lib
parent87fa7eab402cd93796a66ab648eab75909e17254 (diff)
downloadotp-ee44197422710dabe43f2f4b80d1034aae9c916f.tar.gz
otp-ee44197422710dabe43f2f4b80d1034aae9c916f.tar.bz2
otp-ee44197422710dabe43f2f4b80d1034aae9c916f.zip
Add documentation of the built-in logger handlers
Diffstat (limited to 'lib')
-rw-r--r--lib/kernel/doc/src/Makefile1
-rw-r--r--lib/kernel/doc/src/logger_chapter.xml178
-rw-r--r--lib/kernel/doc/src/logger_disk_log_h.xml146
-rw-r--r--lib/kernel/doc/src/logger_std_h.xml110
-rw-r--r--lib/kernel/doc/src/ref_man.xml1
-rw-r--r--lib/kernel/doc/src/specs.xml1
-rw-r--r--lib/kernel/src/logger_h_common.erl4
7 files changed, 406 insertions, 35 deletions
diff --git a/lib/kernel/doc/src/Makefile b/lib/kernel/doc/src/Makefile
index 10bdf46119..82869d7b15 100644
--- a/lib/kernel/doc/src/Makefile
+++ b/lib/kernel/doc/src/Makefile
@@ -58,6 +58,7 @@ XML_REF3_FILES = application.xml \
init_stub.xml \
logger.xml \
logger_std_h.xml \
+ logger_disk_log_h.xml \
logger_filters.xml \
logger_formatter.xml \
net_adm.xml \
diff --git a/lib/kernel/doc/src/logger_chapter.xml b/lib/kernel/doc/src/logger_chapter.xml
index 2a325453da..0bc3b37476 100644
--- a/lib/kernel/doc/src/logger_chapter.xml
+++ b/lib/kernel/doc/src/logger_chapter.xml
@@ -296,6 +296,7 @@
</section>
<section>
+ <marker id="handler_configuration"/>
<title>Handler configuration</title>
<taglist>
<tag><c>level</c></tag>
@@ -577,8 +578,8 @@ log(#{msg:={F,A}},#{myhandler_fd:=Fd}) ->
<p>For examples of overload protection, please refer to the
implementation
of <seealso marker="logger_std_h"><c>logger_std_h</c></seealso>
- and <!--<seealso marker="logger_disk_log_h"--><c>logger_disk_log_h</c>
- <!--/seealso-->.</p>
+ and <seealso marker="logger_disk_log_h"><c>logger_disk_log_h</c>
+ </seealso>.</p>
<p>Below is a simpler example of a handler which logs through one
single process, and uses the default formatter to gain a common
@@ -632,6 +633,179 @@ my_report_cb(R) ->
</code>
</section>
+ <section>
+ <marker id="overload_protection"/>
+ <title>Protecting the handler from overload</title>
+ <p>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
+ <seealso marker="logger_std_h"><c>logger_std_h</c></seealso>
+ and <seealso marker="logger_disk_log_h"><c>logger_disk_log_h</c>
+ </seealso> handler. The mechanism, used by both handlers, works
+ as follows:</p>
+
+ <section>
+ <title>Message queue length</title>
+ <p>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:</p>
+
+ <taglist>
+ <tag><c>toggle_sync_qlen</c></tag>
+ <item>
+ <p>The default value of this level is <c>10</c> 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 <c>toggle_sync_qlen</c> 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 can not protect the handler sufficiently in situations of many
+ concurrent senders.</p>
+ </item>
+ <tag><c>drop_new_reqs_qlen</c></tag>
+ <item>
+ <p>When the message queue has grown larger than this threshold, which
+ defaults to <c>200</c> 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.</p>
+ </item>
+ <tag><c>flush_reqs_qlen</c></tag>
+ <item>
+ <p>Above this threshold, which defaults to <c>1000</c> 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).</p>
+ </item>
+ </taglist>
+
+ <p>For the overload protection algorithm to work properly, it is a
+ requirement that:</p>
+
+ <p><c>toggle_sync_qlen &lt; drop_new_reqs_qlen &lt; flush_reqs_qlen</c></p>
+
+ <p>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. </p>
+
+ <p>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).</p>
+
+ <p>A configuration example:</p>
+ <code type="none">
+logger:add_handler(my_standard_h, logger_std_h,
+ #{logger_std_h =>
+ #{type => {file,"./system_info.log"},
+ toggle_sync_qlen => 100,
+ drop_new_reqs_qlen => 1000,
+ flush_reqs_qlen => 2000}}).
+ </code>
+ </section>
+
+ <section>
+ <title>Controlling bursts of log requests</title>
+ <p>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 console, with massive amounts of
+ printouts. These are the configuration parameters:</p>
+
+ <taglist>
+ <tag><c>enable_burst_limit</c></tag>
+ <item>
+ <p>This is set to <c>true</c> by default. The value <c>false</c>
+ disables the burst control feature.</p>
+ </item>
+ <tag><c>burst_limit_size</c></tag>
+ <item>
+ <p>This is how many requests should be processed within the
+ <c>burst_window_time</c> time frame. After this maximum has been
+ reached, successive requests will be dropped until the end of the
+ time frame. The default value is <c>500</c> messages.</p>
+ </item>
+ <tag><c>burst_window_time</c></tag>
+ <item>
+ <p>The default window is <c>1000</c> milliseconds long.</p>
+ </item>
+ </taglist>
+
+ <p>A configuration example:</p>
+ <code type="none">
+logger:add_handler(my_disk_log_h, logger_disk_log_h,
+ #{disk_log_opts =>
+ #{file => "./my_disk_log"},
+ logger_disk_log_h =>
+ #{burst_limit_size => 10,
+ burst_window_time => 500}}).
+ </code>
+ </section>
+
+ <section>
+ <title>Terminating a large handler</title>
+ <p>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:</p>
+
+ <taglist>
+ <tag><c>enable_kill_overloaded</c></tag>
+ <item>
+ <p>This is set to <c>false</c> by default. The value <c>true</c>
+ enables the feature.</p>
+ </item>
+ <tag><c>handler_overloaded_qlen</c></tag>
+ <item>
+ <p>This is the maximum allowed queue length. If the mailbox grows larger
+ than this, the handler process gets terminated.</p>
+ </item>
+ <tag><c>handler_overloaded_mem</c></tag>
+ <item>
+ <p>This is the maximum allowed memory usage of the handler process. If
+ the handler grows any larger, the process gets terminated.</p>
+ </item>
+ <tag><c>handler_restart_after</c></tag>
+ <item>
+ <p>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 <c>5000</c> is the default value. The value <c>never</c> can
+ also be set, which prevents a restart.</p>
+ </item>
+ </taglist>
+ </section>
+ </section>
<section>
<title>See Also</title>
diff --git a/lib/kernel/doc/src/logger_disk_log_h.xml b/lib/kernel/doc/src/logger_disk_log_h.xml
new file mode 100644
index 0000000000..90cc4fec30
--- /dev/null
+++ b/lib/kernel/doc/src/logger_disk_log_h.xml
@@ -0,0 +1,146 @@
+<?xml version="1.0" encoding="utf-8" ?>
+<!DOCTYPE erlref SYSTEM "erlref.dtd">
+
+<erlref>
+ <header>
+ <copyright>
+ <year>2017</year>
+ <holder>Ericsson AB. All Rights Reserved.</holder>
+ </copyright>
+ <legalnotice>
+ Licensed under the Apache License, Version 2.0 (the "License");
+ you may not use this file except in compliance with the License.
+ You may obtain a copy of the License at
+
+ http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing, software
+ distributed under the License is distributed on an "AS IS" BASIS,
+ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ See the License for the specific language governing permissions and
+ limitations under the License.
+
+ </legalnotice>
+
+ <title>logger_disk_log_h</title>
+ <prepared></prepared>
+ <responsible></responsible>
+ <docno></docno>
+ <approved></approved>
+ <checked></checked>
+ <date></date>
+ <rev>A</rev>
+ <file>logger_disk_log_h.xml</file>
+ </header>
+ <module>logger_disk_log_h</module>
+ <modulesummary>A disk_log based handler for the Logger
+ application.</modulesummary>
+
+ <description>
+ <p>This is a handler for the Logger application that offers circular
+ (wrapped) logs by using the disk_log application. Multiple instances
+ of this handler can be added to logger, and each instance will print to
+ its own disk_log file, created with the name and settings specified in
+ the handler configuration.</p>
+ <p>The default standard handler,
+ <seealso marker="logger_std_h"><c>logger_std_h</c></seealso>, can be
+ replaced by a disk_log handler at startup of the kernel application.
+ See an example of this below.</p>
+ <p>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
+ <seealso marker="logger_chapter#overload_protection"><c>User's Guide</c>
+ </seealso>.</p>
+ <p>To add a new instance of the disk_log handler, use
+ <seealso marker="logger#add_handler-3"><c>logger:add_handler/3</c>
+ </seealso>. The handler configuration argument is a map which may contain
+ general configuration parameters, as documented in the
+ <seealso marker="logger_chapter#handler_configuration"><c>User's Guide</c>
+ </seealso>, as well as handler specific parameters.</p>
+ <p>The settings for the disk_log log file should be specified with the
+ key <c>disk_log_opts</c>. These settings are a subset of the disk_log
+ datatype
+ <seealso marker="disk_log#open-1"><c>dlog_option()</c></seealso>.</p>
+ <p>Parameters in the <c>disk_log_opts</c> map:</p>
+ <taglist>
+ <tag><c>file</c></tag>
+ <item>This is the full name of the disk_log log file.</item>
+ <tag><c>type</c></tag>
+ <item>This is the disk_log type, <c>wrap</c> or <c>halt</c>. The
+ default value is <c>wrap</c>.</item>
+ <tag><c>max_no_files</c></tag>
+ <item>This is the maximum number of files that disk_log will use
+ for its circular logging. The default value is <c>10</c>. (The setting
+ has no effect on a halt log).</item>
+ <tag><c>max_no_bytes</c></tag>
+ <item>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 <c>1048576</c> bytes, and <c>infinity</c> for a halt
+ log.</item>
+ </taglist>
+ <p>Specific configuration for the handler (represented as a sub map)
+ is specified with the key <c>logger_disk_log_h</c>. It may contain the
+ following parameter:</p>
+ <taglist>
+ <tag><c>filesync_repeat_interval</c></tag>
+ <item>
+ <p>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 <c>5000</c> milliseconds.
+ If <c>no_repeat</c> is set as value, the repeated sync operation is
+ disabled. The user can also call the
+ <seealso marker="logger_disk_log_h#disk_log_sync-1"><c>disk_log_sync/1</c>
+ </seealso> function to perform a disk_log sync.</p></item>
+ </taglist>
+ <p>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
+ <seealso marker="logger_chapter#overload_protection"><c>User's Guide</c>
+ </seealso>.</p>
+ <p>Note that when changing the configuration of the handler in runtime, by
+ calling
+ <seealso marker="logger#set_handler_config-2"><c>logger:set_handler_config/2
+ or logger:set_handler_config/3</c></seealso>, the <c>disk_log_opts</c>
+ settings may not be modified.</p>
+ <p>Example of adding a disk_log handler:</p>
+ <code type="none">
+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},
+ logger_disk_log_h =>
+ #{filesync_repeat_interval => 1000}}).
+ </code>
+ <p>In order to use the disk_log handler instead of the default standard
+ handler when starting en Erlang node, use the kernel configuration parameter
+ <seealso marker="kernel_app#configuration"><c>logger_dest</c></seealso> with
+ value <c>{disk_log,FileName}</c>. Example:</p>
+ <code type="none">
+erl -kernel logger_dest '{disk_log,"./system_disk_log"}'
+ </code>
+ </description>
+
+ <funcs>
+
+ <func>
+ <name name="disk_log_sync" arity="1" clause_i="1"/>
+ <fsummary>Writes buffered data to disk.</fsummary>
+ <desc>
+ <p>Write buffered data to disk.</p>
+ </desc>
+ </func>
+
+ </funcs>
+
+</erlref>
+
+
diff --git a/lib/kernel/doc/src/logger_std_h.xml b/lib/kernel/doc/src/logger_std_h.xml
index 2a368b16eb..fe9b9ca5a9 100644
--- a/lib/kernel/doc/src/logger_std_h.xml
+++ b/lib/kernel/doc/src/logger_std_h.xml
@@ -39,42 +39,94 @@
<p>This is the default handler for the Logger
application. Multiple instances of this handler can be added to
logger, and each instance will print logs to <c>standard_io</c>,
- <c>standard_error</c> or to a file.</p>
-
- <p>To add a new instance,
- use <seealso marker="logger#add_handler-3"><c>logger:add_handler/3</c>
+ <c>standard_error</c> or to file. The default instance that starts
+ with kernel is named <c>logger_std_h</c> - which is the name to be used
+ for reconfiguration.</p>
+ <p>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
+ <seealso marker="logger_chapter#overload_protection"><c>User's Guide</c>
</seealso>.</p>
-
- <p>The handler configuration may contain the following keys,
- associated with values as described:</p>
+ <p>To add a new instance of the standard handler, use
+ <seealso marker="logger#add_handler-3"><c>logger:add_handler/3</c>
+ </seealso>. The handler configuration argument is a map which may contain
+ general configuration parameters, as documented in the
+ <seealso marker="logger_chapter#handler_configuration"><c>User's Guide</c>
+ </seealso>, as well as handler specific parameters. The specific parameters
+ are stored in a sub map with the key <c>logger_std_h</c>. The following
+ keys and values may be specified:</p>
<taglist>
- <tag><c>filters</c></tag>
- <item>
- <p>A list of <c>{Id,{Fun,Args}}</c>, each representing a filter
- that may selct or modify log events to forward to this
- handler.</p></item>
- <tag><c>filter_default</c></tag>
- <item>
- <p>The atom <c>log</c> or <c>stop</c>, specifying what to
- do with a log event if all filters
- return <c>ignore</c>.</p></item>
- <tag><c>formatter</c></tag>
+ <tag><c>type</c></tag>
<item>
- <p><c>{Module,Extra}</c>,
- where <c>Module:format(Log,Extra)</c> will be called by
- the handler to produce the string that will be printed to
- the handler's destination.</p></item>
- <tag><c>level</c></tag>
+ <p>This will have the value <c>standard_io</c>, <c>standard_error</c>,
+ <c>{file,LogFileName}</c>, or <c>{file,LogFileName,LogFileOpts}</c>,
+ where <c>standard_io</c> is the default value for type. It's recommended
+ to not specify <c>LogFileOpts</c> if not absolutely necessary. The
+ default options used by the handler to open a file for logging are:
+ <c>raw</c>, <c>append</c> and <c>delayed_write</c>. The standard
+ handler does not have support for circular logging. Use the
+ <seealso marker="logger_disk_log_h"><c>logger_disk_log_h</c>
+ </seealso> handler for this.</p></item>
+ <tag><c>filesync_repeat_interval</c></tag>
<item>
- <p>The level of log events that <c>logger</c> shall forward to
- this handler. Log events of the specified, or more severe
- levels, are forwarded.</p></item>
+ <p>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 <c>5000</c> milliseconds.
+ If <c>no_repeat</c> 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 <seealso marker="logger_std_h#filesync-1"><c>filesync/1</c></seealso>
+ function to perform a file sync.</p></item>
</taglist>
-
+ <p>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
+ <seealso marker="logger_chapter#overload_protection"><c>User's Guide</c>
+ </seealso>.</p>
+ <p>Note that when changing the configuration of the handler in runtime, by
+ calling
+ <seealso marker="logger#set_handler_config-2"><c>logger:set_handler_config/2</c>
+ </seealso>, or
+ <seealso marker="logger#set_handler_config-3"><c>logger:set_handler_config/3</c>
+ </seealso>,
+ the <c>type</c> parameter may not be modified.</p>
+ <p>Example of adding a standard handler:</p>
+ <code type="none">
+logger:add_handler(my_standard_h, logger_std_h,
+ #{level => info,
+ filter_default => log,
+ logger_std_h =>
+ #{type => {file,"./system_info.log"},
+ filesync_repeat_interval => 1000}}).
+ </code>
+ <p>In order to configure the default handler (that starts initially with
+ the kernel application) to log to file instead of <c>standard_io</c>,
+ use the kernel configuration parameter
+ <seealso marker="kernel_app#configuration"><c>logger_dest</c></seealso> with
+ value <c>{file,FileName}</c>. Example:</p>
+ <code type="none">
+erl -kernel logger_dest '{file,"./erl.log"}'
+ </code>
+ <p>An example of how to replace the standard handler with a disk_log handler
+ at startup can be found in the manual of
+ <seealso marker="logger_disk_log_h"><c>logger_disk_log_h</c></seealso>.</p>
</description>
-<!-- <funcs>
- </funcs> -->
+ <funcs>
+
+ <func>
+ <name name="filesync" arity="1" clause_i="1"/>
+ <fsummary>Writes buffered data to disk.</fsummary>
+ <desc>
+ <p>Write buffered data to disk.</p>
+ </desc>
+ </func>
+
+ </funcs>
</erlref>
diff --git a/lib/kernel/doc/src/ref_man.xml b/lib/kernel/doc/src/ref_man.xml
index 7f4d5b384f..c06914d23d 100644
--- a/lib/kernel/doc/src/ref_man.xml
+++ b/lib/kernel/doc/src/ref_man.xml
@@ -56,6 +56,7 @@
<xi:include href="logger_filters.xml"/>
<xi:include href="logger_formatter.xml"/>
<xi:include href="logger_std_h.xml"/>
+ <xi:include href="logger_disk_log_h.xml"/>
<xi:include href="net_adm.xml"/>
<xi:include href="net_kernel.xml"/>
<xi:include href="os.xml"/>
diff --git a/lib/kernel/doc/src/specs.xml b/lib/kernel/doc/src/specs.xml
index a67e26ef16..bcc422930e 100644
--- a/lib/kernel/doc/src/specs.xml
+++ b/lib/kernel/doc/src/specs.xml
@@ -24,6 +24,7 @@
<xi:include href="../specs/specs_logger_filters.xml"/>
<xi:include href="../specs/specs_logger_formatter.xml"/>
<xi:include href="../specs/specs_logger_std_h.xml"/>
+ <xi:include href="../specs/specs_logger_disk_log_h.xml"/>
<xi:include href="../specs/specs_net_adm.xml"/>
<xi:include href="../specs/specs_net_kernel.xml"/>
<xi:include href="../specs/specs_os.xml"/>
diff --git a/lib/kernel/src/logger_h_common.erl b/lib/kernel/src/logger_h_common.erl
index 7a5082fb84..7caad366ae 100644
--- a/lib/kernel/src/logger_h_common.erl
+++ b/lib/kernel/src/logger_h_common.erl
@@ -133,10 +133,6 @@ call_cast_or_drop(Name, Bin) ->
dropped -> ok
catch
_:{timeout,_} ->
- %%! --- Tue Mar 6 23:10:48 2018 --- peppe was here!
- erlang:display('CLIENT_TIMEOUT'),
- %% exit('CLIENT_TIMEOUT'),
-
?observe(Name,{dropped,1})
end;
drop -> ?observe(Name,{dropped,1})