Ejabberd: Hook c2s_auth_result crashed when running ejabberd_c2s:process_auth_result/3

Created on 29 Nov 2020 · 4Comments · Source: processone/ejabberd

Environment

ejabberd version: 20.07
Erlang version: Erlang (SMP,ASYNC_THREADS,HIPE) (BEAM) emulator version 10.3.5.14
OS: FreeBSD 12.1-RELEASE-p7
Installed from: package

Configuration (only if needed): grep -Ev '^$|^\s*#' ejabberd.yml

Config


hosts:
  - localhost
certfiles:
 - /tmp/ejabberdctl734276941/localhost.crt
 - /tmp/ejabberdctl734276941/localhost.key
loglevel: info
listen:
  -
    port: "unix:/tmp/ejabberdctl734276941/c2s.socket"
    ip: "::1"
    module: ejabberd_c2s
    max_stanza_size: 262144
    shaper: c2s_shaper
    access: c2s
    starttls_required: true
s2s_use_starttls: optional
acl:
  local:
    user_regexp: ""
  loopback:
    ip:
      - 127.0.0.0/8
      - ::1/128
access_rules:
  local:
    allow: local
  c2s:
    deny: block
    allow: all
  trusted_network:
    allow: loopback
shaper:
  normal:
    rate: 3000
    burst_size: 20000
  fast: 100000
shaper_rules:
  max_user_sessions: 10
  max_user_offline_messages:
    5000: admin
    100: all
  c2s_shaper:
    none: admin
    normal: all
  s2s_shaper: fast
modules:
  mod_adhoc: {}
  mod_admin_extra: {}
  mod_announce:
    access: announce
  mod_avatar: {}
  mod_blocking: {}
  mod_bosh: {}
  mod_caps: {}
  mod_carboncopy: {}
  mod_client_state: {}
  mod_configure: {}
  mod_disco: {}
  mod_fail2ban: {}
  mod_http_api: {}
  mod_http_upload:
    put_url: https://@HOST@:5443/upload
  mod_last: {}
  mod_mam:
    assume_mam_usage: true
    default: always
  mod_muc:
    access:
      - allow
    access_admin:
      - allow: admin
    access_create: muc_create
    access_persistent: muc_create
    access_mam:
      - allow
    default_room_options:
      mam: true
  mod_muc_admin: {}
  mod_offline:
    access_max_user_messages: max_user_offline_messages
  mod_ping: {}
  mod_privacy: {}
  mod_private: {}
  mod_pubsub:
    access_createnode: pubsub_createnode
    plugins:
      - flat
      - pep
    force_node_config:
      storage:bookmarks:
        access_model: whitelist
  mod_register:
    ip_access: trusted_network
  mod_roster:
    versioning: true
  mod_s2s_dialback: {}
  mod_shared_roster: {}
  mod_stream_mgmt:
    resend_on_timeout: if_offline
  mod_vcard: {}
  mod_vcard_xupdate: {}
  mod_version:
    show_os: false

## Errors from error.log/crash.log

error.log

2020-11-28 20:36:33.387093-05:00 [error] <0.120.0>@ejabberd_app:start_elixir_application/0:192 Elixir application not started.
2020-11-28 20:36:34.513610-05:00 [error] <0.658.0>@ejabberd_hooks:safe_apply/4:240 Hook c2s_auth_result crashed when running ejabberd_c2s:process_auth_result/3:
** exception error: bad argument
   in function  list_to_binary/1
      called as list_to_binary({error,einval})
   in call from misc:ip_to_list/1 (src/misc.erl, line 221)
   in call from ejabberd_c2s:process_auth_result/3 (src/ejabberd_c2s.erl, line 271)
   in call from ejabberd_hooks:safe_apply/4 (src/ejabberd_hooks.erl, line 236)
   in call from ejabberd_hooks:run_fold1/4 (src/ejabberd_hooks.erl, line 217)
   in call from xmpp_stream_in:process_sasl_success/3 (src/xmpp_stream_in.erl, line 923)
   in call from xmpp_stream_in:handle_info/2 (src/xmpp_stream_in.erl, line 404)
   in call from p1_server:handle_msg/8 (src/p1_server.erl, line 696)
** Arg 1 = #{lserver => <<"localhost">>,stream_direction => in,
             mgmt_resend => if_offline,stream_authenticated => false,
             xmlns => <<"jabber:client">>,mgmt_max_timeout => 300000,
             tls_options => [compression_none],
             mgmt_ack_timeout => 60000,tls_enabled => false,resource => <<>>,
             tls_required => true,stream_restarted => true,lang => <<"en">>,
             stream_state => wait_for_sasl_request,owner => <0.658.0>,
             mgmt_max_queue => 5000,stream_id => <<"1482542940736864366">>,
             server => <<"localhost">>,mgmt_stanzas_req => 0,
             stream_version => {1,0},
             stream_header_sent => true,mod => ejabberd_c2s,
             shaper => c2s_shaper,mgmt_timeout => 300000,
             stream_encrypted => true,zlib => false,
             sasl_state =>
                 {sasl_state,<<"localhost">>,<<>>,undefined,
                     #Fun,
                     #Fun,
                     #Fun},
             sasl_mech => <<"PLAIN">>,mgmt_queue_type => ram,
             stream_compressed => false,
             ip => {local,<<>>},
             socket =>
                 {socket_state,fast_tls,
                     {tlssock,#Port<0.25>,#Ref<0.3588478267.945946625.34957>},
                     262144,#Ref<0.3588478267.945946625.34922>,
                     {state,3000,20000,19921,1606613794511957},
                     none},
             pres_a => {0,nil},
             mgmt_state => inactive,csi_state => active,access => c2s,
             tls_verify => false,
             stream_timeout => {30000,-576460750385},
             csi_queue => {0,#{}},
             auth_module => ejabberd_auth_mnesia,
             codec_options => [ignore_els],
             mgmt_stanzas_in => 0,
             socket_monitor => #Ref<0.3588478267.945815553.34923>,
             mgmt_stanzas_out => 0,user => <<>>}
** Arg 2 = true
** Arg 3 = <<"me">>
2020-11-28 20:36:35.166620-05:00 [error] <0.70.0>@supervisor_bridge:report_error/3:149 SUPERVISOR REPORT:
    supervisor: {<0.70.0>,user_sup}
    errorContext: child_terminated
    reason: epipe
    offender: [{pid,<0.71.0>},{mod,user_sup}]

2020-11-28 20:36:35.167220-05:00 [error] <0.70.0>@gen_server:error_info/7:934 ** Generic server <0.70.0> terminating 
** Last message in was {'EXIT',<0.71.0>,epipe}
** When Server state == {state,user_sup,undefined,<0.71.0>,
                               {<0.70.0>,user_sup}}
** Reason for termination ==
** epipe

2020-11-28 20:36:35.167768-05:00 [error] <0.70.0>@proc_lib:crash_report/4:525 CRASH REPORT:
  crasher:
    initial call: supervisor_bridge:user_sup/1
    pid: <0.70.0>
    registered_name: []
    exception exit: epipe
      in function  gen_server:handle_common_reply/8 (gen_server.erl, line 796)
    ancestors: [kernel_sup,<0.47.0>]
    message_queue_len: 0
    messages: []
    links: [<0.49.0>]
    dictionary: []
    trap_exit: true
    status: running
    heap_size: 4185
    stack_size: 28
    reductions: 14942
  neighbours:

2020-11-28 20:36:35.168560-05:00 [error] <0.49.0>@supervisor:do_restart/3:722 SUPERVISOR REPORT:
    supervisor: {local,kernel_sup}
    errorContext: child_terminated
    reason: epipe
    offender: [{pid,<0.70.0>},
               {id,user},
               {mfargs,{user_sup,start,[]}},
               {restart_type,temporary},
               {shutdown,2000},
               {child_type,supervisor}]

Bug description

As far as I can tell this doesn't cause any problems, but I have errors in the logs so I wanted to report them. Specifically the stuff arond Hook c2s_auth_result crashed when running ejabberd_c2s:process_auth_result/3.

Bug

Source

SamWhited

❤1

All 4 comments

listen:
  -
    port: "unix:/tmp/ejabberdctl734276941/c2s.socket"

According to the docs, port should be a number. How does that work for you?

badlop on 1 Dec 2020

We support Unix Domain Sockets now, so I guess the docs should be updated.

weiss on 1 Dec 2020

👍1

I commited fix in e937ff62fe76b9a55cc473e40892d701a9b0b972, seems that i never tested this without proxy_protocol: true (where we are getting real ip addresses from our proxy).