Hook s2s_out_unauthenticated_features crashed when running mod_s2s_bidi:s2s_out_unauthenticated_features/2

licaon-kter commented 3 weeks ago

Environment

ejabberd version: HEAD ( https://github.com/processone/ejabberd/commit/601fcba4cbf881942fae4ab89bc8f666f7a9213f )
Erlang version: Erlang (SMP,ASYNC_THREADS) (BEAM) emulator version 15.1.1 self built arm64
OS: Debian 11 arm64
Installed from: source

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

will clean up if needed

Errors from error.log/crash.log

https://gist.github.com/licaon-kter/5adf043e301f818d6afc8e791e2a0e54

Seeing this error when trying to join some MUCs on other domains, and in regards to info pulled from some contacts (avatar, presence etc) on those domains and others.

fyi I don't have mod_s2s_dialback activated, and https://docs.ejabberd.im/admin/configuration/modules#mod_s2s_bidi does not say it needs it.

Reading https://xmpp.org/extensions/xep-0288.html it seems to say that both SASL and Dialback should work separately

/LE: clarified

mwild1 commented 3 weeks ago

Looking at logs from attempted s2s with a Prosody instance with bidi enabled, it looks like ejabberd may be sending (and expecting) the wrong namespace. This causes an unsupported-stanza-type error on both sides (depending who initiates the connection).

XEP-0288 says to send <bidi xmlns='urn:xmpp:bidi'/> but I think ejabberd is sending <bidi xmlns='urn:xmpp:features:bidi'/>.

The urn:xmpp:features:bidi namespace should only used for the <bidi/> element that appears inside stream:features.

licaon-kter commented 3 weeks ago

yup https://github.com/search?q=repo%3Aprocessone%2Fxmpp%20urn%3Axmpp%3Afeatures%3Abidi&type=code

Neustradamus commented 3 weeks ago

@mwild1: Good catch!

bestperson-free commented 2 weeks ago

I also get errors, this is a bug, it will be fixed, or should I do something myself?

2024-11-05 21:22:51.191568+00:00 [error] <0.684.0>@ejabberd_hooks:safe_apply/4:460 Hook s2s_out_unauthenticated_features crashed when running mod_s2s_bidi:s2s_out_unauthenticated_features/2:
** exception error: no try clause matching false
   in function  mod_s2s_bidi:s2s_out_unauthenticated_features/2 (src/mod_s2s_bidi.erl, line 85)
   in call from ejabberd_hooks:safe_apply/4 (src/ejabberd_hooks.erl, line 456)
   in call from ejabberd_hooks:run_fold1/4 (src/ejabberd_hooks.erl, line 403)
   in call from xmpp_stream_out:process_features/2 (/home/runner/work/ejabberd/ejabberd/deps/xmpp/src/xmpp_stream_out.erl, line 614)
   in call from xmpp_stream_out:handle_info/2 (/home/runner/work/ejabberd/ejabberd/deps/xmpp/src/xmpp_stream_out.erl, line 437)
   in call from p1_server:handle_msg/8 (/home/runner/work/ejabberd/ejabberd/deps/p1_utils/src/p1_server.erl, line 696)
   in call from proc_lib:init_p_do_apply/3 (proc_lib.erl, line 241)
** Arg 1 = #{owner => <0.684.0>,user => <<>>,
             socket =>
                 {socket_state,gen_tcp,#Port<0.22>,infinity,
                               #Ref<0.2212199805.1582956545.74203>,none,none,
                               none},
             ip => {{52,213,172,32},5269},
             queue =>
                 {{[{iq,<<"7410c91b-e5f8-4754-99eb-7f0733eb01ca">>,get,
                        <<"en">>,
                        {jid,<<"fgfhfgjghf">>,<<"jabber.angelka.ru">>,
                             <<"gajim.9GSAQH7S">>,<<"fgfhfgjghf">>,
                             <<"jabber.angelka.ru">>,<<"gajim.9GSAQH7S">>},
                        {jid,<<"ejabberd">>,<<"conference.process-one.net">>,
                             <<>>,<<"ejabberd">>,
                             <<"conference.process-one.net">>,<<>>},
                        [{xmlel,<<"query">>,
                                [{<<"xmlns">>,
                                  <<"http://jabber.org/protocol/disco#info">>}],
                                []}],
                        #{ip => {104,28,198,245}}}],
                   []},
                  1,unlimited},
             mod => ejabberd_s2s_out,server => <<"jabber.angelka.ru">>,
             resource => <<>>,password => <<>>,
             codec_options => [ignore_els],
             shaper => none,lang => <<"ru">>,stream_encrypted => false,
             remote_server => <<"conference.process-one.net">>,
             server_host => <<"jabber.angelka.ru">>,
             xmlns => <<"jabber:server">>,db_enabled => true,
             on_route => queue,stream_id => <<"18083496495655325779">>,
             stream_remote_id => <<"9037820848178693379">>,
             stream_state => wait_for_features,
             stream_timeout => -576460548914,
             socket_monitor => #Ref<0.2212199805.1582825473.74204>,
             stream_authenticated => false,stream_direction => out,
             stream_restarted => false,
             stream_version => {1,0},
             stream_verified => false}
** Arg 2 = {stream_features,[{xmlel,<<"mechanisms">>,
                                    [{<<"xmlns">>,
                                      <<"urn:ietf:params:xml:ns:xmpp-sasl">>}],
                                    []},
                             {xmlel,<<"starttls">>,
                                    [{<<"xmlns">>,
                                      <<"urn:ietf:params:xml:ns:xmpp-tls">>}],
                                    []},
                             {xmlel,<<"dialback">>,
                                    [{<<"xmlns">>,
                                      <<"urn:xmpp:features:dialback">>}],
                                    [{xmlel,<<"errors">>,[],[]}]}]}
2024-11-05 21:22:51.439345+00:00 [error] <0.684.0>@ejabberd_hooks:safe_apply/4:460 Hook s2s_out_unauthenticated_features crashed when running mod_s2s_bidi:s2s_out_unauthenticated_features/2:
** exception error: no try clause matching false
   in function  mod_s2s_bidi:s2s_out_unauthenticated_features/2 (src/mod_s2s_bidi.erl, line 85)
   in call from ejabberd_hooks:safe_apply/4 (src/ejabberd_hooks.erl, line 456)
   in call from ejabberd_hooks:run_fold1/4 (src/ejabberd_hooks.erl, line 403)
   in call from xmpp_stream_out:process_features/2 (/home/runner/work/ejabberd/ejabberd/deps/xmpp/src/xmpp_stream_out.erl, line 614)
   in call from xmpp_stream_out:handle_info/2 (/home/runner/work/ejabberd/ejabberd/deps/xmpp/src/xmpp_stream_out.erl, line 437)
   in call from p1_server:handle_msg/8 (/home/runner/work/ejabberd/ejabberd/deps/p1_utils/src/p1_server.erl, line 696)
   in call from proc_lib:init_p_do_apply/3 (proc_lib.erl, line 241)
** Arg 1 = #{owner => <0.684.0>,user => <<>>,
             socket =>
                 {socket_state,fast_tls,
                     {tlssock,#Port<0.22>,#Ref<0.2212199805.1582956545.74267>},
                     infinity,#Ref<0.2212199805.1582956545.74203>,none,none,
                     <<"/opt/ejabberd/database/ejabberd@localhost/certs/f898d03ecd2f92f498742bdcfb48b3e71d46ce39">>},
             ip => {{52,213,172,32},5269},
             queue =>
                 {{[{iq,<<"7410c91b-e5f8-4754-99eb-7f0733eb01ca">>,get,
                        <<"en">>,
                        {jid,<<"fgfhfgjghf">>,<<"jabber.angelka.ru">>,
                            <<"gajim.9GSAQH7S">>,<<"fgfhfgjghf">>,
                            <<"jabber.angelka.ru">>,<<"gajim.9GSAQH7S">>},
                        {jid,<<"ejabberd">>,<<"conference.process-one.net">>,
                            <<>>,<<"ejabberd">>,
                            <<"conference.process-one.net">>,<<>>},
                        [{xmlel,<<"query">>,
                             [{<<"xmlns">>,
                               <<"http://jabber.org/protocol/disco#info">>}],
                             []}],
                        #{ip => {104,28,198,245}}}],
                   []},
                  1,unlimited},
             mod => ejabberd_s2s_out,server => <<"jabber.angelka.ru">>,
             resource => <<>>,password => <<>>,
             codec_options => [ignore_els],
             shaper => none,lang => <<"ru">>,stream_encrypted => true,
             remote_server => <<"conference.process-one.net">>,
             server_host => <<"jabber.angelka.ru">>,
             xmlns => <<"jabber:server">>,db_enabled => true,
             on_route => queue,stream_id => <<"262705101536686341">>,
             stream_remote_id => <<"9429984280823064290">>,
             stream_state => wait_for_features,
             stream_timeout => -576460548914,
             socket_monitor => #Ref<0.2212199805.1582825473.74204>,
             stream_authenticated => false,stream_direction => out,
             stream_restarted => true,
             stream_version => {1,0},
             stream_verified => false}
** Arg 2 = {stream_features,
               [{xmlel,<<"mechanisms">>,
                    [{<<"xmlns">>,<<"urn:ietf:params:xml:ns:xmpp-sasl">>}],
                    [{xmlel,<<"mechanism">>,[],[{xmlcdata,<<"EXTERNAL">>}]}]},
                {xmlel,<<"sasl-channel-binding">>,
                    [{<<"xmlns">>,<<"urn:xmpp:sasl-cb:0">>}],
                    [{xmlel,<<"channel-binding">>,
                         [{<<"type">>,<<"tls-exporter">>}],
                         []},
                     {xmlel,<<"channel-binding">>,
                         [{<<"type">>,<<"tls-server-end-point">>}],
                         []}]},
                {xmlel,<<"dialback">>,
                    [{<<"xmlns">>,<<"urn:xmpp:features:dialback">>}],
                    [{xmlel,<<"errors">>,[],[]}]}]}

prefiks commented 2 weeks ago

Fix for that crash should be available in d56eae809d505ea0442a30beb26951d51e84a4be

mwild1 commented 2 weeks ago

Great! Just the bad namespace to fix next :) (do you need a separate issue for tracking that?)

licaon-kter commented 2 weeks ago

I updated yesterday, I could join Monal support room on yax.im all day... until 1h ago, now it saysStream closed by peer: unsupported-stanza-type if I try to post, and the channel is not connected. I sometimes see 1 or 2 members in list.

Looking in my logs, I got this spam every 3 mins or so [warning] <0.1025.0>@ejabberd_s2s_out:process_closed/2:157 Failed to establish outbound s2s connection mydomain -> chat.yax.im: Stream closed by peer: unsupported-stanza-type; bouncing for 220 seconds for yax.im (where I have contacts) and chat.yax.im (Monal channel) and other domains affected by the bidi issue

I've disabled bidi again.

processone / ejabberd