概要
wsl(wsl2じゃない)でnervesやってみる。
qemu(x86_64エミュレータ、ラズパイじゃない)でやってみた。
練習問題やってみた。
練習問題
さらに調査せよ。
実行結果
iex(2)> use Logger
** (UndefinedFunctionError) function Logger.__using__/1 is undefined or private
(logger 1.13.4) Logger.__using__([])
iex(2)> h Logger
Logger
A logger for Elixir applications.
It includes many features:
? Provides debug, info, warn, and error levels.
? Supports multiple backends which are automatically supervised when
plugged into Logger.
? Formats and truncates messages on the client to avoid clogging Logger
backends.
? Alternates between sync and async modes to remain performant when
required but also apply backpressure when under stress.
? Integrates with Erlang's :logger (:logger) to convert terms to Elixir
syntax.
Logging is useful for tracking when an event of interest happens in your
system. For example, it may be helpful to log whenever a user is deleted.
def delete_user(user) do
Logger.info("Deleting user from the system: #{inspect(user)}")
# ...
end
The Logger.info/2 macro emits the provided message at the :info level. Note the
arguments given to info/2 will only be evaluated if a message is logged. For
instance, if the Logger level is set to :warning, :info messages are never
logged and therefore the arguments given above won't even be executed.
There are additional macros for other levels.
Logger also allows log commands to be removed altogether via the
:compile_time_purge_matching option (see below).
For dynamically logging messages, see bare_log/3. But note that bare_log/3
always evaluates its arguments (unless the argument is an anonymous function).
## Levels
The supported levels, ordered by importance, are:
? :emergency - when system is unusable, panics
? :alert - for alerts, actions that must be taken immediately, ex.
corrupted database
? :critical - for critical conditions
? :error - for errors
? :warning - for warnings
? :notice - for normal, but significant, messages
? :info - for information of any kind
? :debug - for debug-related messages
For example, :info takes precedence over :debug. If your log level is set to
:info, then all :info, :notice and above will be passed to backends. If your
log level is set to :alert, only :alert and :emergency will be printed.
## Metadata
Whenever a message is logged, additional information can be given via metadata.
Each log operation, such as Logger.info/2, allows metadata to be given as an
argument.
Furthermore, metadata can be set per process with Logger.metadata/1.
Some metadata, however, is always added automatically by Logger whenever
possible. Those are:
? :application - the current application
? :mfa - the current module, function and arity
? :file - the current file
? :line - the current line
? :pid - the current process identifier
? :initial_call - the initial call that started the process
? :registered_name - the process registered name as an atom
? :domain - a list of domains for the logged message. For example, all
Elixir reports default to [:elixir]. Erlang reports may start with [:otp]
or [:sasl]
? :crash_reason - a two-element tuple with the throw/error/exit reason as
first argument and the stacktrace as second. A throw will always be
{:nocatch, term}. An error is always an Exception struct. All other entries
are exits. The console backend ignores this metadata by default but it can
be useful to other backends, such as the ones that report errors to
third-party services
Note that all metadata is optional and may not always be available. The :mfa,
:file, :line, and similar metadata are automatically included when using Logger
macros. Logger.bare_log/3 does not include any metadata beyond the :pid by
default. Other metadata, such as :crash_reason, :initial_call, and
:registered_name are available only inside behaviours such as GenServer,
Supervisor, and others.
For example, you might wish to include a custom :error_code metadata in your
logs:
Logger.error("We have a problem", [error_code: :pc_load_letter])
In your app's logger configuration, you would need to include the :error_code
key and you would need to include $metadata as part of your log format
template:
config :logger, :console,
format: "[$level] $message $metadata\n",
metadata: [:error_code, :file]
Your logs might then receive lines like this:
[error] We have a problem error_code=pc_load_letter file=lib/app.ex
## Configuration
Logger supports a wide range of configurations.
This configuration is split in three categories:
? Application configuration - must be set before the :logger application
is started
? Runtime configuration - can be set before the :logger application is
started, but may be changed during runtime
? Erlang configuration - options that handle integration with Erlang's
logging facilities
### Application configuration
The following configuration must be set via config files (such as
config/config.exs) before the :logger application is started.
? :backends - the backends to be used. Defaults to [:console]. See the
"Backends" section for more information.
? :compile_time_application - sets the :application metadata value to the
configured value at compilation time. This configuration is automatically
set by Mix and made available as metadata when logging.
? :compile_time_purge_matching - purges at compilation time all calls
that match the given conditions. This means that Logger calls with level
lower than this option will be completely removed at compile time, accruing
no overhead at runtime. This configuration expects a list of keyword lists.
Each keyword list contains a metadata key and the matching value that
should be purged. Some special keys are supported:
? :level_lower_than - purges all messages with a lower logger level
? :module - purges all messages with the matching module
? :function - purges all messages with the "function/arity"
Remember that if you want to purge log calls from a dependency, the
dependency must be recompiled.
? :start_options - passes start options to Logger's main process, such as
:spawn_opt and :hibernate_after. All options in t:GenServer.option/0 are
accepted, except :name.
For example, to configure the :backends and purge all calls that happen at
compile time with level lower than :info in a config/config.exs file:
config :logger,
backends: [:console],
compile_time_purge_matching: [
[level_lower_than: :info]
]
If you want to purge all log calls from an application named :foo and only keep
errors from Bar.foo/3, you can set up two different matches:
config :logger,
compile_time_purge_matching: [
[application: :foo],
[module: Bar, function: "foo/3", level_lower_than: :error]
]
### Runtime Configuration
All configuration below can be set via config files (such as config/config.exs)
but also changed dynamically during runtime via Logger.configure/1.
? :level - the logging level. Attempting to log any message with severity
less than the configured level will simply cause the message to be ignored.
Keep in mind that each backend may have its specific level, too. In
addition to levels mentioned above it also support 2 "meta-levels":
? :all - all messages will be logged, conceptually identical to
:debug
? :none - no messages will be logged at all
? :utc_log - when true, uses UTC in logs. By default it uses local time
(i.e., it defaults to false).
? :truncate - the maximum message size to be logged (in bytes). Defaults
to 8192 bytes. Note this configuration is approximate. Truncated messages
will have " (truncated)" at the end. The atom :infinity can be passed to
disable this behavior.
? :sync_threshold - if the Logger manager has more than :sync_threshold
messages in its queue, Logger will change to sync mode*, to apply
backpressure to the clients. `Logger` will return to *async mode once the
number of messages in the queue is reduced to one below the sync_threshold.
Defaults to 20 messages. :sync_threshold can be set to 0 to force sync
mode.
? :discard_threshold - if the Logger manager has more than
:discard_threshold messages in its queue, Logger will change to discard
mode and messages will be discarded directly in the clients. Logger will
return to sync mode once the number of messages in the queue is reduced to
one below the discard_threshold. Defaults to 500 messages.
? :discard_threshold_periodic_check - a periodic check that checks and
reports if logger is discarding messages. It logs a warning message
whenever the system is (or continues) in discard mode and it logs a warning
message whenever if the system was discarding messages but stopped doing so
after the previous check. By default it runs every 30_000 milliseconds.
? :translator_inspect_opts - when translating OTP reports and errors, the
last message and state must be inspected in the error reports. This
configuration allow developers to change how much and how the data should
be inspected.
For example, to configure the :level and :truncate options in a
config/config.exs file:
config :logger,
level: :warning,
truncate: 4096
### Erlang/OTP integration
From Elixir v1.10, Elixir's Logger is fully integrated with Erlang's logger.
They share the same Logger.level/0, any metadata set with Logger.metadata/1
applies to both, and so on.
Elixir also supports formatting Erlang reports using Elixir syntax. This can be
controlled with two configurations:
? :handle_otp_reports - redirects OTP reports to Logger so they are
formatted in Elixir terms. This effectively disables Erlang standard
logger. Defaults to true.
? :handle_sasl_reports - redirects supervisor, crash and progress reports
to Logger so they are formatted in Elixir terms. Your application must
guarantee :sasl is started before :logger. This means you may see some
initial reports written in Erlang syntax until the Logger application kicks
in. Defaults to false. This option only has an effect if
:handle_otp_reports is true.
For example, to configure Logger to redirect all Erlang messages using a
config/config.exs file:
config :logger,
handle_otp_reports: true,
handle_sasl_reports: true
Furthermore, Logger allows messages sent by Erlang to be translated into an
Elixir format via translators. Translators can be added at any time with the
add_translator/1 and remove_translator/1 APIs. Check Logger.Translator for more
information.
## Backends
Logger supports different backends where log messages are written to.
The available backends by default are:
? :console - logs messages to the console (enabled by default). :console
is simply a shortcut for Logger.Backends.Console.
Developers may also implement their own backends, an option that is explored in
more detail below.
The initial backends are loaded via the :backends configuration, which must be
set before the :logger application is started. However, by the time the Logger
application starts, the code for your own and third-party backends may not yet
be available. For this reason, it is preferred to add and remove backends via
add_backend/2 and remove_backend/2 functions. This is often done in your
c:Application.start/2 callback:
@impl true
def start(_type, _args) do
Logger.add_backend(MyCustomBackend)
The backend can be configured either on the add_backend/2 call:
@impl true
def start(_type, _args) do
Logger.add_backend(MyCustomBackend, some_config: ...)
Or in your config files:
config :logger, MyCustomBackend,
some_config: ...
### Elixir custom backends
Any developer can create their own Logger backend. Since Logger is an event
manager powered by :gen_event, writing a new backend is a matter of creating an
event handler, as described in the :gen_event (:gen_event) documentation.
From now on, we will be using the term "event handler" to refer to your custom
backend, as we head into implementation details.
Once the :logger application starts, it installs all event handlers listed
under the :backends configuration into the Logger event manager. The event
manager and all added event handlers are automatically supervised by Logger.
Note that if a backend fails to start by returning {:error, :ignore} from its
init/1 callback, then it's not added to the backends but nothing fails. If a
backend fails to start by returning {:error, reason} from its init/1 callback,
the :logger application will fail to start.
Once initialized, the handler should be designed to handle the following
events:
? {level, group_leader, {Logger, message, timestamp, metadata}} where:
? level is one of :debug, :info, :warn, or :error, as previously
described (for compatibility with pre 1.10 backends the :notice will be
translated to :info and all messages above :error will be translated to
:error)
? group_leader is the group leader of the process which logged the
message
? {Logger, message, timestamp, metadata} is a tuple containing
information about the logged message:
? the first element is always the atom Logger
? message is the actual message (as chardata)
? timestamp is the timestamp for when the message was logged, as
a {{year, month, day}, {hour, minute, second, millisecond}} tuple
? metadata is a keyword list of metadata used when logging the
message
? :flush
It is recommended that handlers ignore messages where the group leader is in a
different node than the one where the handler is installed. For example:
def handle_event({_level, gl, {Logger, _, _, _}}, state)
when node(gl) != node() do
{:ok, state}
end
In the case of the event :flush handlers should flush any pending data. This
event is triggered by Logger.flush/0.
Furthermore, backends can be configured via the configure_backend/2 function
which requires event handlers to handle calls of the following format:
{:configure, options}
where options is a keyword list. The result of the call is the result returned
by configure_backend/2. The recommended return value for successful
configuration is :ok. For example:
def handle_call({:configure, options}, state) do
new_state = reconfigure_state(state, options)
{:ok, :ok, new_state}
end
It is recommended that backends support at least the following configuration
options:
? :level - the logging level for that backend
? :format - the logging format for that backend
? :metadata - the metadata to include in that backend
Check the Logger.Backends.Console implementation in Elixir's codebase for
examples on how to handle the recommendations in this section and how to
process the existing options.
### Erlang/OTP handlers
While Elixir Logger provides backends, Erlang/OTP logger provides handlers.
They represent the same concept: the ability to integrate into the logging
system to handle each logged message/event.
However, implementation-wise, they have the following differences:
? Elixir backends run in a separate process which comes with overload
protection. However, because this process is a single GenEvent, any long
running action should be avoided, as it can lead to bottlenecks in the
system
? Erlang handlers run in the same process as the process logging the
message/event. This gives developers more flexibility but they should avoid
performing any long running action in such handlers, as it may slow down
the action being executed considerably. At the moment, there is no built-in
overload protection for Erlang handlers, so it is your responsibility to
implement it
The good news is that developers can use third-party implementations of both
Elixir backends and Erlang handlers. We have already covered Elixir backends,
so let's see how to add Erlang/OTP handlers.
Erlang/OTP handlers must be listed under your own application:
config :my_app, :logger, [
{:handler, :name_of_the_handler, ACustomHandler, configuration = %{}}
]
And then, explicitly attached in your c:Application.start/2 callback:
:logger.add_handlers(:my_app)
Note we do not recommend configuring Erlang/OTP's logger directly under the
:kernel application in your config/config.exs, like this:
# Not recommended:
config :kernel, :logger, ...
This is because by the time Elixir starts, Erlang's kernel has already been
started, which means the configuration above would have no effect.
iex(3)> :logger
:logger
iex(4)> Logger.info("hello")
** (UndefinedFunctionError) function Logger.info/1 is undefined or private. However there is a macro with the same name and arity. Be sure to require Logger if you intend to invoke this macro
(logger 1.13.4) Logger.info("hello")
iex(4)> runtime_info
## System and architecture
Elixir version: 1.13.4
Erlang/OTP version: 25
ERTS version: 13.1.3
Compiled for: x86_64-buildroot-linux-musl
Schedulers: 1
Schedulers online: 1
## Memory
Total: 46 MB
Atoms: 992 KB
Binaries: 843 KB
Code: 25 MB
ETS: 1 MB
Processes: 9 MB
## Statistics / limits
Uptime: 10 minutes and 14 seconds
Run queue: 2
Atoms: 32214 / 1048576 (3% used)
ETS: 50 / 8192 (0% used)
Ports: 14 / 65536 (0% used)
Processes: 160 / 262144 (0% used)
Showing topics: [:system, :memory, :limits]
Additional topics: [:applications]
To view a specific topic call runtime_info(topic)
iex(5)> cmd("ps -wlT")
S UID PID PPID VSZ RSS TTY STIME TIME CMD
S 0 1 0 824 624 tty1 06:24 00:00:02 /sbin/init
S 0 2 0 0 0 0:0 06:24 00:00:00 [kthreadd]
I 0 3 2 0 0 0:0 06:24 00:00:00 [rcu_gp]
I 0 4 2 0 0 0:0 06:24 00:00:00 [rcu_par_gp]
I 0 6 2 0 0 0:0 06:24 00:00:00 [kworker/0:0H-ev]
I 0 7 2 0 0 0:0 06:24 00:00:00 [kworker/u2:0-fl]
I 0 8 2 0 0 0:0 06:24 00:00:00 [kworker/0:1H-ev]
I 0 9 2 0 0 0:0 06:24 00:00:00 [mm_percpu_wq]
S 0 10 2 0 0 0:0 06:24 00:00:00 [ksoftirqd/0]
I 0 11 2 0 0 0:0 06:24 00:00:00 [rcu_preempt]
S 0 12 2 0 0 0:0 06:24 00:00:00 [migration/0]
S 0 13 2 0 0 0:0 06:24 00:00:00 [cpuhp/0]
S 0 14 2 0 0 0:0 06:24 00:00:00 [kdevtmpfs]
I 0 15 2 0 0 0:0 06:24 00:00:00 [netns]
S 0 16 2 0 0 0:0 06:24 00:00:00 [rcu_tasks_kthre]
I 0 17 2 0 0 0:0 06:24 00:00:00 [kworker/0:1-eve]
S 0 18 2 0 0 0:0 06:24 00:00:00 [oom_reaper]
I 0 19 2 0 0 0:0 06:24 00:00:00 [writeback]
S 0 20 2 0 0 0:0 06:24 00:00:00 [kcompactd0]
I 0 23 2 0 0 0:0 06:24 00:00:00 [kworker/u2:2]
I 0 32 2 0 0 0:0 06:24 00:00:00 [kblockd]
I 0 33 2 0 0 0:0 06:24 00:00:00 [ata_sff]
S 0 34 2 0 0 0:0 06:24 00:00:00 [watchdogd]
S 0 35 2 0 0 0:0 06:24 00:00:00 [kswapd0]
I 0 36 2 0 0 0:0 06:24 00:00:00 [acpi_thermal_pm]
I 0 37 2 0 0 0:0 06:24 00:00:00 [kworker/0:2-eve]
I 0 38 2 0 0 0:0 06:24 00:00:00 [ipv6_addrconf]
S 0 39 1 1136m 94348 tty1 06:24 00:00:03 /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp -sbwt none -sbwtdc
S 0 43 1 1136m 94348 tty1 06:24 00:00:00 {sys_sig_dispatc} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 44 1 1136m 94348 tty1 06:24 00:00:00 {sys_msg_dispatc} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 45 1 1136m 94348 tty1 06:24 00:00:00 {async_1} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp -sbwt no
R 0 47 1 1136m 94348 tty1 06:24 00:01:03 {1_scheduler} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp -sbw
S 0 48 1 1136m 94348 tty1 06:24 00:00:00 {1_dirty_cpu_sch} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 49 1 1136m 94348 tty1 06:24 00:00:00 {1_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 50 1 1136m 94348 tty1 06:24 00:00:00 {2_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 51 1 1136m 94348 tty1 06:24 00:00:00 {3_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 52 1 1136m 94348 tty1 06:24 00:00:00 {4_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 53 1 1136m 94348 tty1 06:24 00:00:00 {5_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 54 1 1136m 94348 tty1 06:24 00:00:00 {6_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 55 1 1136m 94348 tty1 06:24 00:00:00 {7_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 56 1 1136m 94348 tty1 06:24 00:00:00 {8_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 57 1 1136m 94348 tty1 06:24 00:00:01 {9_dirty_io_sche} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 58 1 1136m 94348 tty1 06:24 00:00:00 {10_dirty_io_sch} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp
S 0 59 1 1136m 94348 tty1 06:24 00:00:00 {1_aux} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp -sbwt none
S 0 60 1 1136m 94348 tty1 06:24 00:00:00 {0_poller} /srv/erlang/erts-13.1.3/bin/beam.smp -Bc -C multi_time_warp -sbwt n
S 0 40 2 0 0 0:0 06:24 00:00:00 [jbd2/vda4-8]
I 0 41 2 0 0 0:0 06:24 00:00:00 [ext4-rsv-conver]
S 0 46 39 796 572 0:0 06:24 00:00:00 erl_child_setup 1024
S 0 61 46 796 392 0:0 06:25 00:00:00 heart -pid 39 -ht 30
S 0 64 46 828 524 0:0 06:25 00:00:00 /srv/erlang/lib/nerves_uevent-0.1.0/priv/uevent modprobe
S 0 69 1 4776 1420 0:0 06:25 00:00:00 /usr/sbin/rngd
S 0 74 1 4776 1420 0:0 06:25 00:05:39 /usr/sbin/rngd
S 0 71 46 792 432 0:0 06:25 00:00:00 /srv/erlang/lib/nerves_logging-0.2.0/priv/kmsg_tailer
S 0 77 46 840 404 0:0 06:25 00:00:00 /srv/erlang/lib/vintage_net-0.12.2/priv/if_monitor
S 0 89 46 796 460 0:0 06:25 00:00:00 /srv/erlang/lib/muontrap-1.1.0/priv/muontrap -- /usr/sbin/ntpd -n -S /srv/erla
S 0 90 89 1032 496 0:0 06:25 00:00:00 /usr/sbin/ntpd -n -S /srv/erlang/lib/nerves_time-0.4.5/priv/ntpd_script -p 0.p
S 0 91 46 796 452 0:0 06:25 00:00:00 /srv/erlang/lib/muontrap-1.1.0/priv/muontrap -- /sbin/udhcpc -f -i eth0 -x hos
S 0 92 91 1032 504 0:0 06:25 00:00:00 /sbin/udhcpc -f -i eth0 -x hostname:nerves-3456 -s /srv/erlang/lib/beam_notify
R 0 114 46 1040 484 0:0 06:36 00:00:00 ps -wlT
0
iex(6)>> exit
Connection to localhost closed.
以上。