时间戳

首页 > 解决方案 > 解决 Logger 后端的应用程序启动错误及其依赖项之一未初始化？

elixir - 解决 Logger 后端的应用程序启动错误及其依赖项之一未初始化？

问题描述

我Logger在我的应用程序中使用这个后端：

在应用程序的mix.exs文件中，在application函数中，:logger_logstash_backend包含在:applications键中（在 之后:timex，它依赖于它）。

当我通过 启动我的应用程序时iex -S mix，我看到很多错误，如下所示：

15:49:48.306 registered_name=Logger function=report_error/5 module=gen_event line=747 file=gen_event.erl pid=<0.2656.0> [error] :gen_event handler {LoggerLogstashBackend, :logstash_log} installed in Logger terminating
** (ArgumentError) argument error
    (stdlib) :ets.lookup(:tzdata_current_release, :release_version)
    lib/tzdata/release_reader.ex:74: Tzdata.ReleaseReader.current_release_from_table/0
    lib/tzdata/release_reader.ex:17: Tzdata.ReleaseReader.simple_lookup/1
    lib/tzdata/release_reader.ex:9: Tzdata.ReleaseReader.zone_and_link_list/0
    lib/tzdata.ex:61: Tzdata.zone_exists?/1
    lib/timezone/timezone.ex:358: Timex.Timezone.resolve/3
    lib/logger_logstash_backend.ex:73: LoggerLogstashBackend.log_event/5
    lib/logger_logstash_backend.ex:40: LoggerLogstashBackend.handle_event/2
    (stdlib) gen_event.erl:577: :gen_event.server_update/4
    (stdlib) gen_event.erl:559: :gen_event.server_notify/4
    (stdlib) gen_event.erl:561: :gen_event.server_notify/4
    (stdlib) gen_event.erl:300: :gen_event.handle_msg/6
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Last message: {:info, #PID<0.63.0>, {Logger, ["Application ", "logger", " started at " | ":nonode@nohost"], {{2020, 1, 6}, {15, 49, 48, 224}}, [function: "info_started/2", module: :application_controller, line: 1926, file: "application_controller.erl", pid: #PID<0.43.0>]}}
State: %{ex_jsx_opts: [:uescape], host: '127.0.0.1', level: :info, metadata: [], name: :logstash_log, port: 4201, socket: #Port<0.2458>, type: "elixir"}

15:49:48.307 function=error_info/7 module=gen_server line=888 file=gen_server.erl pid=<0.2659.0> [error] GenServer #PID<0.2659.0> terminating
** (stop) {:EXIT, {:badarg, [{:ets, :lookup, [:tzdata_current_release, :release_version], []}, {Tzdata.ReleaseReader, :current_release_from_table, 0, [file: 'lib/tzdata/release_reader.ex', line: 74]}, {Tzdata.ReleaseReader, :simple_lookup, 1, [file: 'lib/tzdata/release_reader.ex', line: 17]}, {Tzdata.ReleaseReader, :zone_and_link_list, 0, [file: 'lib/tzdata/release_reader.ex', line: 9]}, {Tzdata, :zone_exists?, 1, [file: 'lib/tzdata.ex', line: 61]}, {Timex.Timezone, :resolve, 3, [file: 'lib/timezone/timezone.ex', line: 358]}, {LoggerLogstashBackend, :log_event, 5, [file: 'lib/logger_logstash_backend.ex', line: 73]}, {LoggerLogstashBackend, :handle_event, 2, [file: 'lib/logger_logstash_backend.ex', line: 40]}, {:gen_event, :server_update, 4, [file: 'gen_event.erl', line: 577]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 559]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 561]}, {:gen_event, :handle_msg, 6, [file: 'gen_event.erl', line: 300]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}}
Last message: {:gen_event_EXIT, {LoggerLogstashBackend, :logstash_log}, {:EXIT, {:badarg, [{:ets, :lookup, [:tzdata_current_release, :release_version], []}, {Tzdata.ReleaseReader, :current_release_from_table, 0, [file: 'lib/tzdata/release_reader.ex', line: 74]}, {Tzdata.ReleaseReader, :simple_lookup, 1, [file: 'lib/tzdata/release_reader.ex', line: 17]}, {Tzdata.ReleaseReader, :zone_and_link_list, 0, [file: 'lib/tzdata/release_reader.ex', line: 9]}, {Tzdata, :zone_exists?, 1, [file: 'lib/tzdata.ex', line: 61]}, {Timex.Timezone, :resolve, 3, [file: 'lib/timezone/timezone.ex', line: 358]}, {LoggerLogstashBackend, :log_event, 5, [file: 'lib/logger_logstash_backend.ex', line: 73]}, {LoggerLogstashBackend, :handle_event, 2, [file: 'lib/logger_logstash_backend.ex', line: 40]}, {:gen_event, :server_update, 4, [file: 'gen_event.erl', line: 577]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 559]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 561]}, {:gen_event, :handle_msg, 6, [file: 'gen_event.erl', line: 300]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}}}
State: {Logger, {LoggerLogstashBackend, :logstash_log}}

15:49:48.315 initial_call=Logger.Watcher.init/1 function=crash_report/4 module=proc_lib line=508 file=proc_lib.erl pid=<0.2659.0> [error] Process #PID<0.2659.0> terminating
** (exit) {:EXIT, {:badarg, [{:ets, :lookup, [:tzdata_current_release, :release_version], []}, {Tzdata.ReleaseReader, :current_release_from_table, 0, [file: 'lib/tzdata/release_reader.ex', line: 74]}, {Tzdata.ReleaseReader, :simple_lookup, 1, [file: 'lib/tzdata/release_reader.ex', line: 17]}, {Tzdata.ReleaseReader, :zone_and_link_list, 0, [file: 'lib/tzdata/release_reader.ex', line: 9]}, {Tzdata, :zone_exists?, 1, [file: 'lib/tzdata.ex', line: 61]}, {Timex.Timezone, :resolve, 3, [file: 'lib/timezone/timezone.ex', line: 358]}, {LoggerLogstashBackend, :log_event, 5, [file: 'lib/logger_logstash_backend.ex', line: 73]}, {LoggerLogstashBackend, :handle_event, 2, [file: 'lib/logger_logstash_backend.ex', line: 40]}, {:gen_event, :server_update, 4, [file: 'gen_event.erl', line: 577]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 559]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 561]}, {:gen_event, :handle_msg, 6, [file: 'gen_event.erl', line: 300]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}}
    (stdlib) gen_server.erl:751: :gen_server.handle_common_reply/8
    (stdlib) proc_lib.erl:249: :proc_lib.init_p_do_apply/3
Initial Call: Logger.Watcher.init/1
Ancestors: [Logger.BackendSupervisor, Logger.Supervisor, #PID<0.2654.0>]
Message Queue Length: 0
Messages: []
Links: [#PID<0.2658.0>, #PID<0.2656.0>]
Dictionary: []
Trapping Exits: true
Status: :running
Heap Size: 4185
Stack Size: 27
Reductions: 57169

15:49:48.316 function=do_restart/3 module=supervisor line=713 file=supervisor.erl pid=<0.2658.0> [error] Child {LoggerLogstashBackend, :logstash_log} of Supervisor Logger.BackendSupervisor terminated
** (exit) {:EXIT, {:badarg, [{:ets, :lookup, [:tzdata_current_release, :release_version], []}, {Tzdata.ReleaseReader, :current_release_from_table, 0, [file: 'lib/tzdata/release_reader.ex', line: 74]}, {Tzdata.ReleaseReader, :simple_lookup, 1, [file: 'lib/tzdata/release_reader.ex', line: 17]}, {Tzdata.ReleaseReader, :zone_and_link_list, 0, [file: 'lib/tzdata/release_reader.ex', line: 9]}, {Tzdata, :zone_exists?, 1, [file: 'lib/tzdata.ex', line: 61]}, {Timex.Timezone, :resolve, 3, [file: 'lib/timezone/timezone.ex', line: 358]}, {LoggerLogstashBackend, :log_event, 5, [file: 'lib/logger_logstash_backend.ex', line: 73]}, {LoggerLogstashBackend, :handle_event, 2, [file: 'lib/logger_logstash_backend.ex', line: 40]}, {:gen_event, :server_update, 4, [file: 'gen_event.erl', line: 577]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 559]}, {:gen_event, :server_notify, 4, [file: 'gen_event.erl', line: 561]}, {:gen_event, :handle_msg, 6, [file: 'gen_event.erl', line: 300]}, {:proc_lib, :init_p_do_apply, 3, [file: 'proc_lib.erl', line: 249]}]}}
Pid: #PID<0.2659.0>
Start Call: Logger.Watcher.start_link({Logger, {LoggerLogstashBackend, :logstash_log}, {LoggerLogstashBackend, :logstash_log}})
Restart: :transient
Shutdown: 5000
Type: :worker

15:49:48.316 function=report_progress/2 module=supervisor line=1419 file=supervisor.erl pid=<0.2658.0> [info]  Child {LoggerLogstashBackend, :logstash_log} of Supervisor Logger.BackendSupervisor started
Pid: #PID<0.2678.0>
Start Call: Logger.Watcher.start_link({Logger, {LoggerLogstashBackend, :logstash_log}, {LoggerLogstashBackend, :logstash_log}})
Restart: :transient
Shutdown: 5000
Type: :worker

（最后一个事件不是错误。）

这些错误似乎是由于后端依赖于tzdata已启动且其 ETS 表存在。

直到今天我一直忽略错误。今天，我的整个应用程序第一次无法启动，因为在足够短的时间内最终出现了足够多的上述错误，以至于监督树本身崩溃了。

我尝试将后端的应用程序从:applications键移动到start_phase函数，但这似乎根本没有帮助。我猜这是因为后端的应用程序是自己启动的Logger。

如何解决或预防这些错误？应该（理想情况下）在我的应用程序或后端更改什么以避免此或类似问题？

是后端依赖的问题Timex吗tzdata？或者是否有某种方式可以启动后端Logger并等待tzdata（或Timex）完成加载，然后才能开始正常处理日志事件？

后端的 GitHub 项目似乎已经有一段时间没有积极维护了。我实际上正在使用代码的个人分支。因此，我愿意接受更改后端代码的建议。

我之前在Elixir 论坛上发布了一个关于此的主题：

标签： elixir

解决方案

我能够解决/防止所有这些错误（以及解决第一组错误后出现的一些新错误）。

我从:applications密钥中删除了后端 - 无论如何这都很好。稍后我将尝试更一般地清理依赖项，例如:applications完全删除密钥并仅向密钥添加必要的“额外”应用程序:extra_applications。（我的应用程序比 Elixir 中的那些更改更旧；因此此代码/配置处于陈旧状态。）

我修改了我的Logger配置以不包括这个后端。相反，我为应用程序添加了一个“开始阶段”；在mix.exs：

       # Start `logger_logstash_backend` after `timex` (and `tzdata`) have been started:
       start_phases: [{:logger_logstash_backend, []}]

在我的主应用程序模块中：

  def start_phase(:logger_logstash_backend, _start_type, _phase_args) do
    IO.puts "Starting application start phase `:logger_logstash_backend`"

    case Application.fetch_env(:my_app, :logger_logstash_backend) do
      :error ->
        IO.puts "No configuration value was found for the Logger Logstash backend."

      {:ok, options} ->
        backend = {LoggerLogstashBackend, :logstash_log}

        # From the docs for `Logger.add_backend`:
        #
        # > Backends added by this function are not persisted. Therefore
        # > if the Logger application or supervision tree is restarted,
        # > the backend won't be available. If you need this guarantee,
        # > then configure the backend via the application environment.
        #
        # This shouldn't be an issue for us as the `Logger` application and supervision tree don't seem
        # to have ever needed to be restarted; just started normally when the app is started, i.e. when
        # running the app locally in a `:dev` environment or when starting a new instance in production.

        Logger.add_backend(backend)
        Logger.configure_backend(backend, options)
    end

    :ok
  end

这感觉像是解决此类问题的“正确方法”，例如，在应用程序启动期间需要启动应用程序或其他“服务器”进程，但在它依赖的其他一些应用程序或服务器进程之后启动。

推荐阅读