DEVHIDE
Login Or Sign up

resend_on_timeout seems to be ignored by Ejabberd

990 Views Asked by At

I'm new to Ejabberd and I've been trying to configure it so that it is robust to connection losses following those recommendations: Dead connections, message loss, and outdated presence Stream management is activated by default (I use ejabberd 15.07), I set resend_on_timeout to true in ejabberd.yml:

listen: 
  - 
    port: 5222
    module: ejabberd_c2s
    resend_on_timeout: true
    max_stanza_size: 65536
    shaper: c2s_shaper
    access: c2s
    starttls: true
    certfile: "/Applications/ejabberd-15.07/conf/server.pem"

and mod_offline is activated:

mod_offline: 
  access_max_user_messages: max_user_offline_messages

Furthermore, the admin web interface confirms that resend_on_timeout is set to true:

[{certfile,
  <<47, 65, 112, 112, 108, 105, 99, 97,
    116, 105, 111, 110, 115, 47, 101,
    106, 97, 98, 98, 101, 114, 100, 45,
    49, 53, 46, 48, 55, 47, 99, 111,
    110, 102, 47, 115, 101, 114, 118,
    101, 114, 46, 112, 101, 109>>},
 {starttls, true}, {access, c2s},
 {shaper, c2s_shaper},
 {max_stanza_size, 65536},
 {resend_on_timeout, true}]

Unfortunately, the following scenario does not work as expected:

  1. user_a and user_b connect to ejabberd
  2. user_b tells ejabberd that he implements XEP-0198: Stream Management
  3. user_b looses his connection without properly disconnecting from Ejabberd
  4. user_a sends the message "Test message" to user_b

  5. Ejabberd detects that user_b did not acknowledge the message

    2015-09-04 00:30:49.869 [info] <0.458.0>@ejabberd_c2s:handle_unacked_stanzas:2877 1 stanzas were not acknowledged by user_b@localhost/7952730381441319317654314

  6. Ejabberd sends an error message to user_a instead of storing the message offline for user_b

    2015-09-04 00:30:49.870 [debug] <0.467.0>@ejabberd_c2s:send_text:1901 Send XML on stream = <<"<message from='user_b@localhost/7952730381441319317654314' to='user_a@localhost/MacBook Air de Cyrille' type='error' id='8C843796-CD60-4111-8754-EBAE20A0D75E'><body>Test message</body>\n<html xmlns='http://jabber.org/protocol/xhtml-im'><body xmlns='http://www.w3.org/1999/xhtml' style='background-color:#e9e9e9;color:#000000;'><span style='font-family: &apos;Helvetica&apos;;font-size: 12px;'>Test message</span></body></html><x xmlns='jabber:x:event'><composing/></x>\n<active xmlns='http://jabber.org/protocol/chatstates'/><error code='503' type='cancel'><service-unavailable xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></message>">>

(The full log is available at the end)

I'm sure I'm missing something but I could not find what. Many thanks in advance for your help.

Full ejabberd log from step 4 to 6

2015-09-04 00:30:19.862 [debug] <0.466.0>@ejabberd_receiver:process_data:349 Received XML on stream = <<"Test message\nhttp://jabber.org/protocol/xhtml-im\">http://www.w3.org/1999/xhtml\" style=\"background-color:#e9e9e9;color:#000000;\">Test message\nhttp://jabber.org/protocol/chatstates\"/>\n">>

2015-09-04 00:30:19.862 [debug] <0.466.0>@shaper:update:120 State: {maxrate,1000,523.8875943484103,1441319395776490}, Size=477
M=323.1461223235512, I=24086.201
2015-09-04 00:30:19.863 [debug] <0.467.0>@ejabberd_router:do_route:323 route
    from {jid,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>}
    to {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    packet {xmlel,<<"message">>,[{<<"to">>,<<"user_b@localhost/7952730381441319317654314">>},{<<"type">>,<<"chat">>},{<<"id">>,<<"8C843796-CD60-4111-8754-EBAE20A0D75E">>}],[{xmlel,<<"body">>,[],[{xmlcdata,<<"Test message">>}]},{xmlcdata,<<"\n">>},{xmlel,<<"html">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/xhtml-im">>}],[{xmlel,<<"body">>,[{<<"xmlns">>,<<"http://www.w3.org/1999/xhtml">>},{<<"style">>,<<"background-color:#e9e9e9;color:#000000;">>}],[{xmlel,<<"span">>,[{<<"style">>,<<"font-family: 'Helvetica';font-size: 12px;">>}],[{xmlcdata,<<"Test message">>}]}]}]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:event">>}],[{xmlel,<<"composing">>,[],[]}]},{xmlcdata,<<"\n">>},{xmlel,<<"active">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/chatstates">>}],[]}]}
2015-09-04 00:30:19.863 [debug] <0.467.0>@ejabberd_local:do_route:296 local route
    from {jid,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>}
    to {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    packet {xmlel,<<"message">>,[{<<"to">>,<<"user"...>>},{<<"type">>,<<...>>},{<<...>>,...}],[{xmlel,<<...>>,...},{xmlcdata,...},{...}|...]}
2015-09-04 00:30:19.864 [debug] <0.467.0>@ejabberd_sm:do_route:447 session manager
    from {jid,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>}
    to {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    packet {xmlel,<<"message">>,[{<<"to">>,<<"user"...>>},{<<"type">>,<<...>>},{<<...>>,...}],[{xmlel,<<...>>,...},{xmlcdata,...},{...}|...]}
2015-09-04 00:30:19.864 [debug] <0.467.0>@ejabberd_sm:do_route:565 sending to process <0.458.0>
2015-09-04 00:30:19.864 [debug] <0.456.0>@ejabberd_http_bind:prepare_response:917 OutPacket: [{xmlstreamelement,{xmlel,<<"message">>,[{<<"from">>,<<"user_a@localhost/MacBook Air de Cyrille">>},{<<"to">>,<<"user_b@localhost/7952730381441319317654314">>},{<<"type">>,<<"chat">>},{<<"id">>,<<"8C843796-CD60-4111-8754-EBAE20A0D75E">>}],[{xmlel,<<"body">>,[],[{xmlcdata,<<"Test message">>}]},{xmlcdata,<<"\n">>},{xmlel,<<"html">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/xhtml-im">>}],[{xmlel,<<"body">>,[{<<"xmlns">>,<<"http://www.w3.org/1999/xhtml">>},{<<"style">>,<<"background-color:#e9e9e9;color:#000000;">>}],[{xmlel,<<"span">>,[{<<"style">>,<<"font-family: 'Helvetica';font-size: 12px;">>}],[{xmlcdata,<<"Test message">>}]}]}]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:event">>}],[{xmlel,<<"composing">>,[],[]}]},{xmlcdata,<<"\n">>},{xmlel,<<"active">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/chatstates">>}],[]}]}}]
2015-09-04 00:30:19.865 [debug] <0.456.0>@ejabberd_http_bind:send_outpacket:1059  --- outgoing data --- 
<body xmlns='http://jabber.org/protocol/httpbind'><message xmlns='jabber:client' from='user_a@localhost/MacBook Air de Cyrille' to='user_b@localhost/7952730381441319317654314' type='chat' id='8C843796-CD60-4111-8754-EBAE20A0D75E'><body>Test message</body>
<html xmlns='http://jabber.org/protocol/xhtml-im'><body xmlns='http://www.w3.org/1999/xhtml' style='background-color:#e9e9e9;color:#000000;'><span style='font-family: &apos;Helvetica&apos;;font-size: 12px;'>Test message</span></body></html><x xmlns='jabber:x:event'><composing/></x>
<active xmlns='http://jabber.org/protocol/chatstates'/></message></body>
 --- END --- 
2015-09-04 00:30:30.178 [debug] <0.466.0>@ejabberd_receiver:process_data:349 Received XML on stream = <<"\r\n">>
2015-09-04 00:30:30.179 [debug] <0.466.0>@shaper:update:120 State: {maxrate,1000,271.84566900163605,1441319419862845}, Size=2
M=1.1573040463605986, I=10315.866
2015-09-04 00:30:49.865 [info] <0.457.0>@ejabberd_http_bind:handle_info:522 Session timeout. Closing the HTTP bind session: <<"4388150e84a2c3e491fb66d9ff77ae9b78492cde">>
2015-09-04 00:30:49.865 [debug] <0.457.0>@ejabberd_http_bind:terminate:558 terminate: Deleting session 4388150e84a2c3e491fb66d9ff77ae9b78492cde
2015-09-04 00:30:49.865 [info] <0.458.0>@ejabberd_c2s:terminate:1842 ({socket_state,ejabberd_http_bind,{http_bind,<0.457.0>,{{127,0,0,1},55272}},ejabberd_http_bind}) Close session for user_b@localhost/7952730381441319317654314
2015-09-04 00:30:49.866 [debug] <0.458.0>@mod_pubsub:node_action:4118 node_action <<"pubsub.localhost">> <<"flat">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}]
2015-09-04 00:30:49.866 [debug] <0.458.0>@mod_pubsub:node_call:4099 node_call <<"flat">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}]
2015-09-04 00:30:49.866 [debug] <0.458.0>@mod_pubsub:node_action:4118 node_action <<"pubsub.localhost">> <<"hometree">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}]
2015-09-04 00:30:49.867 [debug] <0.458.0>@mod_pubsub:node_call:4099 node_call <<"hometree">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}]
2015-09-04 00:30:49.867 [debug] <0.458.0>@mod_pubsub:node_action:4118 node_action <<"pubsub.localhost">> <<"pep">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}]
2015-09-04 00:30:49.867 [debug] <0.458.0>@mod_pubsub:node_call:4099 node_call <<"pep">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}]
2015-09-04 00:30:49.867 [debug] <0.458.0>@mod_carboncopy:disable:249 disabling for <<"user_b">>
2015-09-04 00:30:49.867 [debug] <0.458.0>@mod_shared_roster:unset_presence:1104 unset_presence for <<"user_b">> @ <<"localhost">> / <<"7952730381441319317654314">> -> <<>> (0 resources)
2015-09-04 00:30:49.868 [debug] <0.458.0>@ejabberd_router_multicast:do_route:193 route_multicast
    from user_b@localhost/7952730381441319317654314
    domain localhost
    destinations [<<"user_b@localhost">>]
    packet {xmlel,<<"presence">>,[{<<"type">>,<<"unavailable">>}],[]}
2015-09-04 00:30:49.868 [debug] <0.458.0>@ejabberd_router:do_route:323 route
    from {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    to {jid,<<"user_b">>,<<"localhost">>,<<>>,<<"user_b">>,<<"localhost">>,<<>>}
    packet {xmlel,<<"presence">>,[{<<"type">>,<<"unavailable">>}],[]}
2015-09-04 00:30:49.868 [debug] <0.458.0>@ejabberd_local:do_route:296 local route
    from {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    to {jid,<<"user_b">>,<<"localhost">>,<<>>,<<"user_b">>,<<"localhost">>,<<>>}
    packet {xmlel,<<"presence">>,[{<<"type">>,<<"unav"...>>}],[]}
2015-09-04 00:30:49.869 [debug] <0.458.0>@ejabberd_sm:do_route:447 session manager
    from {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    to {jid,<<"user_b">>,<<"localhost">>,<<>>,<<"user_b">>,<<"localhost">>,<<>>}
    packet {xmlel,<<"presence">>,[{<<"type">>,<<"unav"...>>}],[]}
2015-09-04 00:30:49.869 [info] <0.458.0>@ejabberd_c2s:handle_unacked_stanzas:2877 1 stanzas were not acknowledged by user_b@localhost/7952730381441319317654314
2015-09-04 00:30:49.869 [debug] <0.458.0>@ejabberd_router:do_route:323 route
    from {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    to {jid,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>}
    packet {xmlel,<<"message">>,[{<<"type">>,<<"error">>},{<<"to">>,<<"user_a@localhost/MacBook Air de Cyrille">>},{<<"from">>,<<"user_b@localhost/7952730381441319317654314">>},{<<"id">>,<<"8C843796-CD60-4111-8754-EBAE20A0D75E">>}],[{xmlel,<<"body">>,[],[{xmlcdata,<<"Test message">>}]},{xmlcdata,<<"\n">>},{xmlel,<<"html">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/xhtml-im">>}],[{xmlel,<<"body">>,[{<<"xmlns">>,<<"http://www.w3.org/1999/xhtml">>},{<<"style">>,<<"background-color:#e9e9e9;color:#000000;">>}],[{xmlel,<<"span">>,[{<<"style">>,<<"font-family: 'Helvetica';font-size: 12px;">>}],[{xmlcdata,<<"Test message">>}]}]}]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:event">>}],[{xmlel,<<"composing">>,[],[]}]},{xmlcdata,<<"\n">>},{xmlel,<<"active">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/chatstates">>}],[]},{xmlel,<<"error">>,[{<<"code">>,<<"503">>},{<<"type">>,<<"cancel">>}],[{xmlel,<<"service-unavailable">>,[{<<"xmlns">>,<<"urn:ietf:params:xml:ns:xmpp-stanzas">>}],[]}]}]}
2015-09-04 00:30:49.870 [debug] <0.458.0>@ejabberd_local:do_route:296 local route
    from {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    to {jid,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>}
    packet {xmlel,<<"message">>,[{<<"type">>,<<"erro"...>>},{<<"to">>,<<...>>},{<<...>>,...},{...}],[{xmlel,<<...>>,...},{xmlcdata,...},{...}|...]}
2015-09-04 00:30:49.870 [debug] <0.458.0>@ejabberd_sm:do_route:447 session manager
    from {jid,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>,<<"user_b">>,<<"localhost">>,<<"7952730381441319317654314">>}
    to {jid,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>,<<"user_a">>,<<"localhost">>,<<"MacBook Air de Cyrille">>}
    packet {xmlel,<<"message">>,[{<<"type">>,<<"erro"...>>},{<<"to">>,<<...>>},{<<...>>,...},{...}],[{xmlel,<<...>>,...},{xmlcdata,...},{...}|...]}
2015-09-04 00:30:49.870 [debug] <0.458.0>@ejabberd_sm:do_route:565 sending to process <0.467.0>
2015-09-04 00:30:49.870 [debug] <0.467.0>@ejabberd_c2s:send_text:1901 Send XML on stream = <<"<message from='user_b@localhost/7952730381441319317654314' to='user_a@localhost/MacBook Air de Cyrille' type='error' id='8C843796-CD60-4111-8754-EBAE20A0D75E'><body>Test message</body>\n<html xmlns='http://jabber.org/protocol/xhtml-im'><body xmlns='http://www.w3.org/1999/xhtml' style='background-color:#e9e9e9;color:#000000;'><span style='font-family: &apos;Helvetica&apos;;font-size: 12px;'>Test message</span></body></html><x xmlns='jabber:x:event'><composing/></x>\n<active xmlns='http://jabber.org/protocol/chatstates'/><error code='503' type='cancel'><service-unavailable xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></message>">>
configuration yaml ejabberd stream-management
Original Q&A
1

There are 1 best solutions below

4
On BEST ANSWER

You configured resend_on_timeout option on ejabberd c2s listener, but you seem to be using http-bind / Bosh listener. It should work as expected if you set it up on your http bind listener.

Related Questions in CONFIGURATION

Related Questions in YAML

Related Questions in EJABBERD

Related Questions in STREAM-MANAGEMENT

Trending Questions

Popular # Hahtags

javascript python java c# php android html jquery c++ css ios sql mysql r reactjs node.js arrays c asp.net json python-3.x ruby-on-rails .net sql-server swift django angular objective-c pandas excel

Popular Questions

Copyright © 2021 Jogjafile Inc.