Crashing on startup, badmatch error

[wittjosiah]

I have gelf_logger setup as dependency as such {:gelf_logger, "~> 0.7.5"} and my config/prod.exs file is equivalent to the following:

use Mix.Config

# Do not print debug messages in production
config :logger,
  level: :info,
  backends: [:console, {Logger.Backends.Gelf, :gelf_logger}]

config :logger, :gelf_logger,
  host: "gelf.internal.co",
  port: "12201",
  application: "my_app",
  metadata: :all,
  hostname: "my_app@${HOSTNAME}"

I've tried with the port both as an integer and a string. When I run my release PORT=8080 /opt/app/bin/my_app console as it is starting up the following happens and it crashes:

=SUPERVISOR REPORT==== 26-Apr-2019::20:24:37.139709 ===
    supervisor: {local,'Elixir.Logger.Supervisor'}
    errorContext: start_error
    reason: {'EXIT',
             {{badmatch,
               {error,
                {{{case_clause,
                   {'EXIT',
                    {undef,
                     [{'Elixir.Logger.Backends.Gelf',init,
                       [{'Elixir.Logger.Backends.Gelf',gelf_logger}],
                       []},
                      {gen_event,server_add_handler,4,
                       [{file,"gen_event.erl"},{line,473}]},
                      {gen_event,handle_msg,6,
                       [{file,"gen_event.erl"},{line,318}]},
                      {proc_lib,init_p_do_apply,3,
                       [{file,"proc_lib.erl"},{line,249}]}]}}},
                  [{'Elixir.Logger.Watcher',init,1,
                    [{file,"lib/logger/watcher.ex"},{line,28}]},
                   {gen_server,init_it,2,[{file,"gen_server.erl"},{line,374}]},
                   {gen_server,init_it,6,[{file,"gen_server.erl"},{line,342}]},
                   {proc_lib,init_p_do_apply,3,
                    [{file,"proc_lib.erl"},{line,249}]}]},
                 {child,undefined,
                  {'Elixir.Logger.Backends.Gelf',gelf_logger},
                  {'Elixir.Logger.Watcher',start_link,
                   [{'Elixir.Logger',
                     {'Elixir.Logger.Backends.Gelf',gelf_logger},
                     {'Elixir.Logger.Backends.Gelf',gelf_logger}}]},
                  transient,5000,worker,
                  ['Elixir.Logger.Watcher']}}}},
              [{'Elixir.Logger.BackendSupervisor','-start_link/1-fun-0-',2,
                [{file,"lib/logger/backend_supervisor.ex"},{line,14}]},
               {'Elixir.Enum','-reduce/3-lists^foldl/2-0-',3,
                [{file,"lib/enum.ex"},{line,1940}]},
               {'Elixir.Logger.BackendSupervisor',start_link,1,
                [{file,"lib/logger/backend_supervisor.ex"},{line,13}]},
               {supervisor,do_start_child_i,3,
                [{file,"supervisor.erl"},{line,379}]},
               {supervisor,do_start_child,2,
                [{file,"supervisor.erl"},{line,365}]},
               {supervisor,'-start_children/2-fun-0-',3,
                [{file,"supervisor.erl"},{line,349}]},
               {supervisor,children_map,4,
                [{file,"supervisor.erl"},{line,1157}]},
               {supervisor,init_children,2,
                [{file,"supervisor.erl"},{line,315}]}]}}
    offender: [{pid,undefined},
               {id,'Elixir.Logger.BackendSupervisor'},
               {mfargs,{'Elixir.Logger.BackendSupervisor',start_link,[[]]}},
               {restart_type,permanent},
               {shutdown,infinity},
               {child_type,supervisor}]
=CRASH REPORT==== 26-Apr-2019::20:24:37.139267 ===
  crasher:
    initial call: Elixir.Logger.Watcher:init/1
    pid: <0.1668.0>
    registered_name: []
    exception error: no case clause matching
                     {'EXIT',
                         {undef,
                             [{'Elixir.Logger.Backends.Gelf',init,
                                  [{'Elixir.Logger.Backends.Gelf',
                                       gelf_logger}],
                                  []},
                              {gen_event,server_add_handler,4,
                                  [{file,"gen_event.erl"},{line,473}]},
                              {gen_event,handle_msg,6,
                                  [{file,"gen_event.erl"},{line,318}]},
                              {proc_lib,init_p_do_apply,3,
                                  [{file,"proc_lib.erl"},{line,249}]}]}}
      in function  'Elixir.Logger.Watcher':init/1 (lib/logger/watcher.ex, line 28)
      in call from gen_server:init_it/2 (gen_server.erl, line 374)
      in call from gen_server:init_it/6 (gen_server.erl, line 342)
    ancestors: ['Elixir.Logger.BackendSupervisor',
                  'Elixir.Logger.Supervisor',<0.1662.0>]
    message_queue_len: 0
    messages: []
    links: [<0.1666.0>,<0.1664.0>]
    dictionary: []
    trap_exit: true
    status: running
    heap_size: 610
    stack_size: 27
    reductions: 266
  neighbours:

=ERROR REPORT==== 26-Apr-2019::20:24:37.140758 ===
** Generic server <0.1667.0> terminating
** Last message in was {gen_event_EXIT,'Elixir.Logger.Backends.Console',
                           shutdown}
** When Server state == {'Elixir.Logger','Elixir.Logger.Backends.Console'}
** Reason for termination ==
** {noproc,[{gen,do_call,4,[{file,"gen.erl"},{line,177}]},
            {gen_event,rpc,2,[{file,"gen_event.erl"},{line,239}]},
            {'Elixir.Logger.Watcher',terminate,2,
                                     [{file,"lib/logger/watcher.ex"},
                                      {line,90}]},
            {gen_server,try_terminate,3,[{file,"gen_server.erl"},{line,673}]},
            {gen_server,terminate,10,[{file,"gen_server.erl"},{line,858}]},
            {proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,249}]}]}

=CRASH REPORT==== 26-Apr-2019::20:24:37.141115 ===
  crasher:
    initial call: Elixir.Logger.Watcher:init/1
    pid: <0.1667.0>
    registered_name: []
    exception exit: noproc
      in function  gen:do_call/4 (gen.erl, line 177)
      in call from gen_event:rpc/2 (gen_event.erl, line 239)
      in call from 'Elixir.Logger.Watcher':terminate/2 (lib/logger/watcher.ex, line 90)
      in call from gen_server:try_terminate/3 (gen_server.erl, line 673)
      in call from gen_server:terminate/10 (gen_server.erl, line 858)
    ancestors: ['Elixir.Logger.BackendSupervisor',
                  'Elixir.Logger.Supervisor',<0.1662.0>]
    message_queue_len: 1
    messages: [{'EXIT',<0.1666.0>,shutdown}]
    links: []
    dictionary: []
    trap_exit: true
    status: running
    heap_size: 2586
    stack_size: 27
    reductions: 6576
  neighbours:

=SUPERVISOR REPORT==== 26-Apr-2019::20:24:37.141966 ===
    supervisor: {local,'Elixir.Logger.BackendSupervisor'}
    errorContext: shutdown_error
    reason: noproc
    offender: [{pid,<0.1667.0>},
               {id,'Elixir.Logger.Backends.Console'},
               {mfargs,
                   {'Elixir.Logger.Watcher',start_link,
                       [{'Elixir.Logger','Elixir.Logger.Backends.Console',
                            console}]}},
               {restart_type,transient},
               {shutdown,5000},
               {child_type,worker}]
=CRASH REPORT==== 26-Apr-2019::20:24:37.140851 ===
  crasher:
    initial call: application_master:init/4
    pid: <0.1661.0>
    registered_name: []
    exception exit: {{shutdown,
                      {failed_to_start_child,
                       'Elixir.Logger.BackendSupervisor',
                       {'EXIT',
                        {{badmatch,
                          {error,
                           {{{case_clause,
                              {'EXIT',
                               {undef,
                                [{'Elixir.Logger.Backends.Gelf',init,
                                  [{'Elixir.Logger.Backends.Gelf',
                                    gelf_logger}],
                                  []},
                                 {gen_event,server_add_handler,4,
                                  [{file,"gen_event.erl"},{line,473}]},
                                 {gen_event,handle_msg,6,
                                  [{file,"gen_event.erl"},{line,318}]},
                                 {proc_lib,init_p_do_apply,3,
                                  [{file,"proc_lib.erl"},{line,249}]}]}}},
                             [{'Elixir.Logger.Watcher',init,1,
                               [{file,"lib/logger/watcher.ex"},{line,28}]},
                              {gen_server,init_it,2,
                               [{file,"gen_server.erl"},{line,374}]},
                              {gen_server,init_it,6,
                               [{file,"gen_server.erl"},{line,342}]},
                              {proc_lib,init_p_do_apply,3,
                               [{file,"proc_lib.erl"},{line,249}]}]},
                            {child,undefined,
                             {'Elixir.Logger.Backends.Gelf',gelf_logger},
                             {'Elixir.Logger.Watcher',start_link,
                              [{'Elixir.Logger',
                                {'Elixir.Logger.Backends.Gelf',gelf_logger},
                                {'Elixir.Logger.Backends.Gelf',gelf_logger}}]},
                             transient,5000,worker,
                             ['Elixir.Logger.Watcher']}}}},
                         [{'Elixir.Logger.BackendSupervisor',
                           '-start_link/1-fun-0-',2,
                           [{file,"lib/logger/backend_supervisor.ex"},
                            {line,14}]},
                          {'Elixir.Enum','-reduce/3-lists^foldl/2-0-',3,
                           [{file,"lib/enum.ex"},{line,1940}]},
                          {'Elixir.Logger.BackendSupervisor',start_link,1,
                           [{file,"lib/logger/backend_supervisor.ex"},
                            {line,13}]},
                          {supervisor,do_start_child_i,3,
                           [{file,"supervisor.erl"},{line,379}]},
                          {supervisor,do_start_child,2,
                           [{file,"supervisor.erl"},{line,365}]},
                          {supervisor,'-start_children/2-fun-0-',3,
                           [{file,"supervisor.erl"},{line,349}]},
                          {supervisor,children_map,4,
                           [{file,"supervisor.erl"},{line,1157}]},
                          {supervisor,init_children,2,
                           [{file,"supervisor.erl"},{line,315}]}]}}}},
                     {'Elixir.Logger.App',start,[normal,[]]}}
      in function  application_master:init/4 (application_master.erl, line 138)
    ancestors: [<0.1660.0>]
    message_queue_len: 1
    messages: [{'EXIT',<0.1662.0>,normal}]
    links: [<0.1660.0>,<0.1599.0>]
    dictionary: []
    trap_exit: true
    status: running
    heap_size: 1598
    stack_size: 27
    reductions: 276
  neighbours:

=INFO REPORT==== 26-Apr-2019::20:24:37.142650 ===
    application: logger
    exited: {{shutdown,
              {failed_to_start_child,'Elixir.Logger.BackendSupervisor',
               {'EXIT',
                {{badmatch,
                  {error,
                   {{{case_clause,
                      {'EXIT',
                       {undef,
                        [{'Elixir.Logger.Backends.Gelf',init,
                          [{'Elixir.Logger.Backends.Gelf',gelf_logger}],
                          []},
                         {gen_event,server_add_handler,4,
                          [{file,"gen_event.erl"},{line,473}]},
                         {gen_event,handle_msg,6,
                          [{file,"gen_event.erl"},{line,318}]},
                         {proc_lib,init_p_do_apply,3,
                          [{file,"proc_lib.erl"},{line,249}]}]}}},
                     [{'Elixir.Logger.Watcher',init,1,
                       [{file,"lib/logger/watcher.ex"},{line,28}]},
                      {gen_server,init_it,2,
                       [{file,"gen_server.erl"},{line,374}]},
                      {gen_server,init_it,6,
                       [{file,"gen_server.erl"},{line,342}]},
                      {proc_lib,init_p_do_apply,3,
                       [{file,"proc_lib.erl"},{line,249}]}]},
                    {child,undefined,
                     {'Elixir.Logger.Backends.Gelf',gelf_logger},
                     {'Elixir.Logger.Watcher',start_link,
                      [{'Elixir.Logger',
                        {'Elixir.Logger.Backends.Gelf',gelf_logger},
                        {'Elixir.Logger.Backends.Gelf',gelf_logger}}]},
                     transient,5000,worker,
                     ['Elixir.Logger.Watcher']}}}},
                 [{'Elixir.Logger.BackendSupervisor','-start_link/1-fun-0-',
                   2,
                   [{file,"lib/logger/backend_supervisor.ex"},{line,14}]},
                  {'Elixir.Enum','-reduce/3-lists^foldl/2-0-',3,
                   [{file,"lib/enum.ex"},{line,1940}]},
                  {'Elixir.Logger.BackendSupervisor',start_link,1,
                   [{file,"lib/logger/backend_supervisor.ex"},{line,13}]},
                  {supervisor,do_start_child_i,3,
                   [{file,"supervisor.erl"},{line,379}]},
                  {supervisor,do_start_child,2,
                   [{file,"supervisor.erl"},{line,365}]},
                  {supervisor,'-start_children/2-fun-0-',3,
                   [{file,"supervisor.erl"},{line,349}]},
                  {supervisor,children_map,4,
                   [{file,"supervisor.erl"},{line,1157}]},
                  {supervisor,init_children,2,
                   [{file,"supervisor.erl"},{line,315}]}]}}}},
             {'Elixir.Logger.App',start,[normal,[]]}}
    type: permanent
{"Kernel pid terminated",application_controller,"{application_start_failure,logger,{{shutdown,{failed_to_start_child,'Elixir.Logger.BackendSupervisor',{'EXIT',{{badmatch,{error,{{{case_clause,{'EXIT',{undef,[{'Elixir.Logger.Backends.Gelf',init,[{'Elixir.Logger.Backends.Gelf',gelf_logger}],[]},{gen_event,server_add_handler,4,[{file,\"gen_event.erl\"},{line,473}]},{gen_event,handle_msg,6,[{file,\"gen_event.erl\"},{line,318}]},{proc_lib,init_p_do_apply,3,[{file,\"proc_lib.erl\"},{line,249}]}]}}},[{'Elixir.Logger.Watcher',init,1,[{file,\"lib/logger/watcher.ex\"},{line,28}]},{gen_server,init_it,2,[{file,\"gen_server.erl\"},{line,374}]},{gen_server,init_it,6,[{file,\"gen_server.erl\"},{line,342}]},{proc_lib,init_p_do_apply,3,[{file,\"proc_lib.erl\"},{line,249}]}]},{child,undefined,{'Elixir.Logger.Backends.Gelf',gelf_logger},{'Elixir.Logger.Watcher',start_link,[{'Elixir.Logger',{'Elixir.Logger.Backends.Gelf',gelf_logger},{'Elixir.Logger.Backends.Gelf',gelf_logger}}]},transient,5000,worker,['Elixir.Logger.Watcher']}}}},[{'Elixir.Logger.BackendSupervisor','-start_link/1-fun-0-',2,[{file,\"lib/logger/backend_supervisor.ex\"},{line,14}]},{'Elixir.Enum','-reduce/3-lists^foldl/2-0-',3,[{file,\"lib/enum.ex\"},{line,1940}]},{'Elixir.Logger.BackendSupervisor',start_link,1,[{file,\"lib/logger/backend_supervisor.ex\"},{line,13}]},{supervisor,do_start_child_i,3,[{file,\"supervisor.erl\"},{line,379}]},{supervisor,do_start_child,2,[{file,\"supervisor.erl\"},{line,365}]},{supervisor,'-start_children/2-fun-0-',3,[{file,\"supervisor.erl\"},{line,349}]},{supervisor,children_map,4,[{file,\"supervisor.erl\"},{line,1157}]},{supervisor,init_children,2,[{file,\"supervisor.erl\"},{line,315}]}]}}}},{'Elixir.Logger.App',start,[normal,[]]}}}"}
Kernel pid terminated (application_controller) ({application_start_failure,logger,{{shutdown,{failed_to_start_child,'Elixir.Logger.BackendSupervisor',{'EXIT',{{badmatch,{error,{{{case_clause,{'EXIT',{

I'm fairly new to the Erlang/Elixir world and not exactly sure how to decipher this. Is something misconfigured here or is it possible there there's a conflict with another dependency?

[jschniper]

The only thing that stands out at the moment is hostname: "my_app@${HOSTNAME}"

You shouldn't need the my_app@

The host should just be the IP or hostname of your server listening for the GELF messages.

[wittjosiah]

Thanks for taking a look at this @jschniper 😄

My understanding was that host was the server listening for the GELF messages and that hostname was the string name of the host sending them which was dropped into the source field in the GELF message. Did I misunderstand that? Is it the opposite?

[jschniper]

No, you are absolutely right. Sorry, it's been a minute since I've looked at the project. Let me dig a little deeper and see what I can find.

[jschniper]

The more I look at it the more it looks like something related to building the release. Are you using distillery or something else?

[wittjosiah]

Yeah, I'm using distillery to build releases

[jschniper]

Would you mind running MIX_ENV=prod mix release --verbose and making sure that you see gelf_logger in there somewhere?

[wittjosiah]

You're right, it doesn't seem like gelf_logger shows up in the "Discovered Applications" list. I assumed it would be included in the release as a dependency of my application, but I guess not? Do I need to include it explicitly in my distillery release config? Perhaps something like this:

release :my_app do
  set(version: current_version(:my_app_web))

  set(
    applications: [
      :logger,
      :gelf_logger,
      :runtime_tools,
      my_app: :permanent,
      my_app_web: :permanent
    ]
  )
end

[jschniper]

I am surprised it's not being pulled in as well. The above should work or you should be able to modify your mix.exs to include it in the applications or extra_applications list.

[wittjosiah]

Seems like its working now 😄 Thanks for your help debugging this one @jschniper!