Устранение ошибок при запуске приложения для бэкенда Logger и одной из его зависимостей не инициализируется? - PullRequest
Новая
       6

Устранение ошибок при запуске приложения для бэкенда Logger и одной из его зависимостей не инициализируется?

0 голосов
/ 07 января 2020

Я использую этот 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 для бэкэнда кажется, не поддерживается активно в течение некоторого времени. Я на самом деле использую личную ветвь кода в настоящее время. Так что я открыт для предложений по изменению кода бэкенда.

Ранее я публиковал топи c на Elixir Forum по этому поводу:

Ответы [ 2 ]

0 голосов
/ 10 января 2020

Мне удалось разрешить / предотвратить все эти ошибки (и некоторые новые, появившиеся после устранения первого набора).

Я удалил бэкэнд из клавиши :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

Этот чувствует как «правильный способ» решения подобных проблем, например, с приложением или другим «серверным» процессом, который необходимо запустить во время запуска приложения, но после какого-либо другого приложения или серверного процесса, от которого он зависит.

0 голосов
/ 07 января 2020

Хотя сообщение об ошибке может показаться немного запутанным, вы не должны включать :logger_logstash_backend в applications. Весь исходный код LoggerLogstashBackend представляет собой реализацию :gen_event, так как почти все бэкэнды регистратора . Он не реализует поведение Application и не предназначен для использования в качестве приложения.

Ваш applications должен выглядеть как [:logger, :timex], как четко указано в README.

Я не уверен, почему он не жалуется на попытку запуска несуществующего приложения, возможно потому, что стандартная реализация :gen_event, по-видимому, имеет start_link/2 ( или use Timex инъекции это это не .)

UPD Либо измените :applications на :extra_applications, либо явно запустите :tzdata приложение. Timer полагается на него, а :applications отбрасывает все автоматически запущенные цепочки приложений в пользу того, что там явно указано.

Timex не запускается, поскольку полагается на приложение :tzdata, которое не запускается.

...