我无法弄清楚为什么 Ejabberd(14.07 和 14.12)在收到同一会话的“可用”节后关闭 BOSH 会话。
我正在使用 JsJac 作为 Web 客户端库,并且会话正在预绑定服务器端,JsJac 在第一页加载时执行“继承”,并且在重新启动时执行。发生这种情况的情况是在成功连接和聊天之后,我使用 chrome 开发人员工具禁用了网络连接。
Ejabberd 每 15 秒 ping 一次,并在超时时设置为“kill”。ejabberd.yml 中 BOSH 的 Inactivity_timeout 设置为 480。
然后,用户可以单击链接以尝试重新连接。这是调用与初始预绑定+客户端继承完全相同的函数。在看似成功重新连接后,几秒钟后,这是:
Close session for
anonymous.c6502a950667fc79c3e1534559cc02e0@localhost/7f317c7fcbb9fb1b79c414c2d8afe05c
出现在 ejabberd 日志中,并且在聊天中向对方发送了一个不可用的节。
问题:有人知道为什么 BOSH 会议可能会关闭吗?
这是Ejabberd日志的相关部分
2015-01-09 18:25:21.308 [debug] <0.2710.0>@ejabberd_receiver:process_data:343 Received XML on stream = <<"<presence from=\"anonymous.c6502a950667fc79c3e1534559cc02e0@jaxlecho.localhost\" type=\"available\"/>">>
2015-01-09 18:25:21.309 [debug] <0.2710.0>@shaper:update:117 State: {maxrate,50000,1899.4311619841992,1420824321273332}, Size=97
M=0.9887812185897407, I=35.836
2015-01-09 18:25:21.390 [info] <0.2709.0>@ejabberd_listener:accept:313 (#Port<0.41723>) Accepted connection ::FFFF:127.0.0.1:58483 -> ::FFFF:127.0.0.1:5280
2015-01-09 18:25:21.391 [debug] <0.5331.0>@ejabberd_http:init:145 S: [{[<<"presence">>],mod_webpresence},{[<<"captcha">>],ejabberd_captcha},{[<<"admin">>],ejabberd_web_admin},{[<<"http-bind">>],mod_http_bind},{[<<"http-poll">>],ejabberd_http_poll}]
2015-01-09 18:25:21.391 [info] <0.5331.0>@ejabberd_http:init:149 started: {gen_tcp,#Port<0.41723>}
2015-01-09 18:25:21.392 [debug] <0.5331.0>@ejabberd_http:process_header:277 (#Port<0.41723>) http query: 'POST' /http-bind
2015-01-09 18:25:21.392 [debug] <0.5331.0>@ejabberd_http:process_request:438 client data: <<"<body rid='876185' sid='a1e29cded4325f591bdc5b3646a8f3c78553cdd8' xmlns='http://jabber.org/protocol/httpbind' key='38516e6b293e317ee957f6ef74fa23c68a003d19'/>">>
2015-01-09 18:25:21.392 [debug] <0.5331.0>@ejabberd_http:process:350 [<<"http-bind">>] matches [<<"http-bind">>]
2015-01-09 18:25:21.393 [debug] <0.5331.0>@ejabberd_http:process:354 [{'Accept-Language',<<"en-US,en;q=0.8,es;q=0.6,und;q=0.4,nl;q=0.2,ca;q=0.2">>},{'Accept-Encoding',<<"gzip, deflate">>},{'Referer',<<"http://localhost:9080/">>},{'Accept',<<"*/*">>},{'Content-Type',<<"text/xml; charset=UTF-8">>},{'User-Agent',<<"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.95 Safari/537.36">>},{<<"Origin">>,<<"http://localhost:9080">>},{'Content-Length',<<"158">>},{'Connection',<<"close">>},{'Host',<<"vagrant.localhost">>}]
2015-01-09 18:25:21.393 [debug] <0.5331.0>@mod_http_bind:process:68 Incoming data: <body rid='876185' sid='a1e29cded4325f591bdc5b3646a8f3c78553cdd8' xmlns='http://jabber.org/protocol/httpbind' key='38516e6b293e317ee957f6ef74fa23c68a003d19'/>
2015-01-09 18:25:21.393 [debug] <0.5331.0>@ejabberd_http_bind:parse_request:1128 --- incoming data ---
<body rid='876185' sid='a1e29cded4325f591bdc5b3646a8f3c78553cdd8' xmlns='http://jabber.org/protocol/httpbind' key='38516e6b293e317ee957f6ef74fa23c68a003d19'/>
--- END ---
2015-01-09 18:25:21.394 [debug] <0.5331.0>@ejabberd_http_bind:http_put:792 Looking for session: <<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>
2015-01-09 18:25:21.394 [debug] <0.4052.0>@ejabberd_http_bind:handle_sync_event:440 New request: {http_put,876185,[{<<"xmlns">>,<<"http://jabber.org/protocol/httpbind">>},{<<"rid">>,<<"876185">>},{<<"sid">>,<<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>},{<<"key">>,<<"38516e6b293e317ee957f6ef74fa23c68a003d19">>}],[],158,1,<<>>,{{0,0,0,0,0,65535,32512,1},58483}}
2015-01-09 18:25:21.395 [debug] <0.4052.0>@ejabberd_http_bind:handle_http_put_event:575 New request: {http_put,876185,[{<<"xmlns">>,<<"http://jabber.org/protocol/httpbind">>},{<<"rid">>,<<"876185">>},{<<"sid">>,<<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>},{<<"key">>,<<"38516e6b293e317ee957f6ef74fa23c68a003d19">>}],[],158,1,<<>>,{{0,0,0,0,0,65535,32512,1},58483}}
2015-01-09 18:25:21.395 [debug] <0.4052.0>@ejabberd_http_bind:rid_allow:866 Previous rid / New rid: 876184/876185
2015-01-09 18:25:21.396 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:608 Actually processing request: {http_put,876185,[{<<"xmlns">>,<<"http://jabber.org/protocol/httpbind">>},{<<"rid">>,<<"876185">>},{<<"sid">>,<<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>},{<<"key">>,<<"38516e6b293e317ee957f6ef74fa23c68a003d19">>}],[],158,1,<<>>,{{0,0,0,0,0,65535,32512,1},58483}}
2015-01-09 18:25:21.396 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:619 Key/OldKey/NextKey: 38516e6b293e317ee957f6ef74fa23c68a003d19/85e12ff1c2c9590328a5f0a1e58c14e52a8c6c42/85e12ff1c2c9590328a5f0a1e58c14e52a8c6c42
2015-01-09 18:25:21.397 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:659 -- SaveKey: 38516e6b293e317ee957f6ef74fa23c68a003d19
2015-01-09 18:25:21.397 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:671 reqlist: [{hbr,876185,<<"85e12ff1c2c9590328a5f0a1e58c14e52a8c6c42">>,[]},{hbr,876184,<<"85e12ff1c2c9590328a5f0a1e58c14e52a8c6c42">>,[{xmlstreamelement,{xmlel,<<"presence">>,[{<<"from">>,<<"anonymous.c6502a950667fc79c3e1534559cc02e0@jaxlecho.localhost">>},{<<"to">>,<<"agent1@localhost/cb_operator_1420818758533">>},{<<"type">>,<<"available">>},{<<"show">>,<<"chat">>}],[]}}]}]
2015-01-09 18:25:21.398 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:717 really sending now: []
2015-01-09 18:25:31.193 [debug] <0.2648.0>@ejabberd_router:do_route:322 route
from {jid,<<>>,<<"localhost">>,<<>>,<<>>,<<"localhost">>,<<>>}
to {jid,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>}
packet {xmlel,<<"iq">>,[{<<"id">>,<<"4293567110">>},{<<"type">>,<<"get">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}
2015-01-09 18:25:31.194 [debug] <0.2648.0>@ejabberd_local:do_route:296 local route
from {jid,<<>>,<<"localhost">>,<<>>,<<>>,<<"localhost">>,<<>>}
to {jid,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>}
packet {xmlel,<<"iq">>,[{<<"id">>,<<"4293"...>>},{<<"type">>,<<...>>}],[{xmlel,<<...>>,...}]}
2015-01-09 18:25:31.194 [debug] <0.2648.0>@ejabberd_sm:do_route:514 session manager
from {jid,<<>>,<<"localhost">>,<<>>,<<>>,<<"localhost">>,<<>>}
to {jid,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>}
packet {xmlel,<<"iq">>,[{<<"id">>,<<"4293"...>>},{<<"type">>,<<...>>}],[{xmlel,<<...>>,...}]}
2015-01-09 18:25:31.194 [debug] <0.2648.0>@ejabberd_sm:do_route:612 sending to process <0.4053.0>
2015-01-09 18:25:31.195 [debug] <0.5331.0>@ejabberd_http_bind:prepare_response:914 OutPacket: [{xmlstreamelement,{xmlel,<<"iq">>,[{<<"from">>,<<"localhost">>},{<<"to">>,<<"agent1@localhost/cb_operator_1420818758533">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"get">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}}]
2015-01-09 18:25:31.195 [debug] <0.5331.0>@ejabberd_http_bind:send_outpacket:1056 --- outgoing data ---
<body xmlns='http://jabber.org/protocol/httpbind'><iq xmlns='jabber:client' from='localhost' to='agent1@localhost/cb_operator_1420818758533' id='4293567110' type='get'><ping xmlns='urn:xmpp:ping'/></iq></body>
--- END ---
2015-01-09 18:25:31.228 [info] <0.2709.0>@ejabberd_listener:accept:313 (#Port<0.41753>) Accepted connection ::FFFF:127.0.0.1:58484 -> ::FFFF:127.0.0.1:5280
2015-01-09 18:25:31.230 [debug] <0.5332.0>@ejabberd_http:init:145 S: [{[<<"presence">>],mod_webpresence},{[<<"captcha">>],ejabberd_captcha},{[<<"admin">>],ejabberd_web_admin},{[<<"http-bind">>],mod_http_bind},{[<<"http-poll">>],ejabberd_http_poll}]
2015-01-09 18:25:31.231 [info] <0.5332.0>@ejabberd_http:init:149 started: {gen_tcp,#Port<0.41753>}
2015-01-09 18:25:31.231 [debug] <0.5332.0>@ejabberd_http:process_header:277 (#Port<0.41753>) http query: 'POST' /http-bind
2015-01-09 18:25:31.231 [debug] <0.5332.0>@ejabberd_http:process_request:438 client data: <<"<body rid='876186' sid='a1e29cded4325f591bdc5b3646a8f3c78553cdd8' xmlns='http://jabber.org/protocol/httpbind' key='9cffab80935471f419ce5c9201475df5935108d5'><iq xmlns=\"jabber:client\" to=\"localhost\" id=\"4293567110\" type=\"result\"><ping xmlns=\"urn:xmpp:ping\"/></iq></body>">>
2015-01-09 18:25:31.231 [debug] <0.5332.0>@ejabberd_http:process:350 [<<"http-bind">>] matches [<<"http-bind">>]
2015-01-09 18:25:31.232 [debug] <0.5332.0>@ejabberd_http:process:354 [{'Accept-Language',<<"en-US,en;q=0.8,es;q=0.6,und;q=0.4,nl;q=0.2,ca;q=0.2">>},{'Accept-Encoding',<<"gzip, deflate">>},{'Referer',<<"http://localhost:9080/">>},{'Accept',<<"*/*">>},{'Content-Type',<<"text/xml; charset=UTF-8">>},{'User-Agent',<<"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/39.0.2171.95 Safari/537.36">>},{<<"Origin">>,<<"http://localhost:9080">>},{'Content-Length',<<"269">>},{'Connection',<<"close">>},{'Host',<<"vagrant.localhost">>}]
2015-01-09 18:25:31.233 [debug] <0.5332.0>@mod_http_bind:process:68 Incoming data: <body rid='876186' sid='a1e29cded4325f591bdc5b3646a8f3c78553cdd8' xmlns='http://jabber.org/protocol/httpbind' key='9cffab80935471f419ce5c9201475df5935108d5'><iq xmlns="jabber:client" to="localhost" id="4293567110" type="result"><ping xmlns="urn:xmpp:ping"/></iq></body>
2015-01-09 18:25:31.233 [debug] <0.5332.0>@ejabberd_http_bind:parse_request:1128 --- incoming data ---
<body rid='876186' sid='a1e29cded4325f591bdc5b3646a8f3c78553cdd8' xmlns='http://jabber.org/protocol/httpbind' key='9cffab80935471f419ce5c9201475df5935108d5'><iq xmlns="jabber:client" to="localhost" id="4293567110" type="result"><ping xmlns="urn:xmpp:ping"/></iq></body>
--- END ---
2015-01-09 18:25:31.234 [debug] <0.5332.0>@ejabberd_http_bind:http_put:792 Looking for session: <<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:handle_sync_event:440 New request: {http_put,876186,[{<<"xmlns">>,<<"http://jabber.org/protocol/httpbind">>},{<<"rid">>,<<"876186">>},{<<"sid">>,<<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>},{<<"key">>,<<"9cffab80935471f419ce5c9201475df5935108d5">>}],[{xmlel,<<"iq">>,[{<<"xmlns">>,<<"jabber:client">>},{<<"to">>,<<"localhost">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"result">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}],269,1,<<>>,{{0,0,0,0,0,65535,32512,1},58484}}
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:handle_http_put_event:575 New request: {http_put,876186,[{<<"xmlns">>,<<"http://jabber.org/protocol/httpbind">>},{<<"rid">>,<<"876186">>},{<<"sid">>,<<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>},{<<"key">>,<<"9cffab80935471f419ce5c9201475df5935108d5">>}],[{xmlel,<<"iq">>,[{<<"xmlns">>,<<"jabber:client">>},{<<"to">>,<<"localhost">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"result">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}],269,1,<<>>,{{0,0,0,0,0,65535,32512,1},58484}}
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:rid_allow:866 Previous rid / New rid: 876185/876186
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:608 Actually processing request: {http_put,876186,[{<<"xmlns">>,<<"http://jabber.org/protocol/httpbind">>},{<<"rid">>,<<"876186">>},{<<"sid">>,<<"a1e29cded4325f591bdc5b3646a8f3c78553cdd8">>},{<<"key">>,<<"9cffab80935471f419ce5c9201475df5935108d5">>}],[{xmlel,<<"iq">>,[{<<"xmlns">>,<<"jabber:client">>},{<<"to">>,<<"localhost">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"result">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}],269,1,<<>>,{{0,0,0,0,0,65535,32512,1},58484}}
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:619 Key/OldKey/NextKey: 9cffab80935471f419ce5c9201475df5935108d5/38516e6b293e317ee957f6ef74fa23c68a003d19/38516e6b293e317ee957f6ef74fa23c68a003d19
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:659 -- SaveKey: 9cffab80935471f419ce5c9201475df5935108d5
2015-01-09 18:25:31.234 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:671 reqlist: [{hbr,876186,<<"38516e6b293e317ee957f6ef74fa23c68a003d19">>,[]},{hbr,876185,<<"38516e6b293e317ee957f6ef74fa23c68a003d19">>,[{xmlstreamelement,{xmlel,<<"iq">>,[{<<"from">>,<<"localhost">>},{<<"to">>,<<"agent1@localhost/cb_operator_1420818758533">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"get">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}}]}]
2015-01-09 18:25:31.235 [debug] <0.4052.0>@ejabberd_http_bind:process_http_put:717 really sending now: [{xmlel,<<"iq">>,[{<<"xmlns">>,<<"jabber:client">>},{<<"to">>,<<"localhost">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"result">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}]
2015-01-09 18:25:31.235 [debug] <0.4053.0>@ejabberd_router:do_route:322 route
from {jid,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>}
to {jid,<<>>,<<"localhost">>,<<>>,<<>>,<<"localhost">>,<<>>}
packet {xmlel,<<"iq">>,[{<<"to">>,<<"localhost">>},{<<"id">>,<<"4293567110">>},{<<"type">>,<<"result">>}],[{xmlel,<<"ping">>,[{<<"xmlns">>,<<"urn:xmpp:ping">>}],[]}]}
2015-01-09 18:25:31.235 [debug] <0.4053.0>@ejabberd_local:do_route:296 local route
from {jid,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>,<<"agent1">>,<<"localhost">>,<<"cb_operator_1420818758533">>}
to {jid,<<>>,<<"localhost">>,<<>>,<<>>,<<"localhost">>,<<>>}
packet {xmlel,<<"iq">>,[{<<"to">>,<<"loca"...>>},{<<"id">>,<<...>>},{<<...>>,...}],[{xmlel,<<...>>,...}]}
2015-01-09 18:25:31.570 [info] <0.5318.0>@ejabberd_c2s:terminate:1757 ({socket_state,ejabberd_http_bind,{http_bind,<0.5317.0>,{{0,0,0,0,0,65535,32512,1},58451}},ejabberd_http_bind}) Close session for anonymous.c6502a950667fc79c3e1534559cc02e0@localhost/2b8e1ac2921d6d3713396edff70a0d2a
2015-01-09 18:25:31.571 [debug] <0.5318.0>@mod_pubsub:node_action:5143 node_action <<"pubsub.localhost">> <<"flat">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"anonymous.c6502a950667fc79c3e1534559cc02e0">>,<<"localhost">>,<<"2b8e1ac2921d6d3713396edff70a0d2a">>}]
2015-01-09 18:25:31.571 [debug] <0.5318.0>@mod_pubsub:node_call:5124 node_call <<"flat">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"anonymous.c6502a950667fc79c3e1534559cc02e0">>,<<"localhost">>,<<"2b8e1ac2921d6d3713396edff70a0d2a">>}]
2015-01-09 18:25:31.571 [debug] <0.5318.0>@mod_pubsub:node_action:5143 node_action <<"pubsub.localhost">> <<"hometree">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"anonymous.c6502a950667fc79c3e1534559cc02e0">>,<<"localhost">>,<<"2b8e1ac2921d6d3713396edff70a0d2a">>}]
2015-01-09 18:25:31.572 [debug] <0.5318.0>@mod_pubsub:node_call:5124 node_call <<"hometree">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"anonymous.c6502a950667fc79c3e1534559cc02e0">>,<<"localhost">>,<<"2b8e1ac2921d6d3713396edff70a0d2a">>}]
2015-01-09 18:25:31.572 [debug] <0.5318.0>@mod_pubsub:node_action:5143 node_action <<"pubsub.localhost">> <<"pep">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"anonymous.c6502a950667fc79c3e1534559cc02e0">>,<<"localhost">>,<<"2b8e1ac2921d6d3713396edff70a0d2a">>}]
2015-01-09 18:25:31.572 [debug] <0.5318.0>@mod_pubsub:node_call:5124 node_call <<"pep">> get_entity_affiliations [<<"pubsub.localhost">>,{<<"anonymous.c6502a950667fc79c3e1534559cc02e0">>,<<"localhost">>,<<"2b8e1ac2921d6d3713396edff70a0d2a">>}]
2015-01-09 18:25:31.573 [debug] <0.5318.0>@mod_carboncopy:disable:246 disabling for <<"anonymous.c6502a950667fc79c3e1534559cc02e0">>
2015-01-09 18:25:31.574 [debug] <0.5318.0>@mod_shared_roster:unset_presence:1081 unset_presence for <<"anonymous.c6502a950667fc79c3e1534559cc02e0">> @ <<"localhost">> / <<"2b8e1ac2921d6d3713396edff70a0d2a">> -> <<>> (0 resources)
2015-01-09 18:25:31.574 [debug] <0.5318.0>@ejabberd_router:do_route:322 route