2009/12/1 Ian Wilkinson <
the.ian.wilkinson <at> googlemail.com>:
> Hi Pablo,
> Here we go...
> =INFO REPORT==== 2009-12-01 16:39:08 ===
> D(<0.361.0>:ejabberd_receiver:320) : Received XML on stream =
> "<handshake>6a6d862b2693211e4bf90a4d492076af88ddd03d</handshake>"
> =INFO REPORT==== 2009-12-01 16:39:08 ===
> D(<0.361.0>:shaper:61) : State: {maxrate,50000,2480.006151953245,
> 1259685547992503}, Size=63
> M=0.6460213697117849, I=17.433
>
> =INFO REPORT==== 2009-12-01 16:39:08 ===
> I(<0.362.0>:ejabberd_service:217) : Route registered for service
> "feeds.macintosh-4.local"
>
> =INFO REPORT==== 2009-12-01 16:40:19 ===
> I(<0.362.0>:ejabberd_service:364) : terminated: normal
> =INFO REPORT==== 2009-12-01 16:41:28 ===
> I(<0.356.0>:ejabberd_listener:229) : (#Port<0.428>) Accepted connection
> {{127,0,0,1},64249} -> {{127,0,0,1},5222}
> =INFO REPORT==== 2009-12-01 16:41:28 ===
> D(<0.377.0>:ejabberd_receiver:320) : Received XML on stream =
> "<stream:stream xmlns:stream=\"
http://etherx.jabber.org/streams\"
> xmlns=\"jabber:client\" to=\"macintosh-4.local\">"
> =INFO REPORT==== 2009-12-01 16:41:28 ===
> D(<0.378.0>:ejabberd_c2s:1376) : Send XML on stream = "<?xml
> version='1.0'?><stream:stream xmlns='jabber:client'
> xmlns:stream='
http://etherx.jabber.org/streams' id='3670992088'
> from='macintosh-4.local' xml:lang='en'>"
> =INFO REPORT==== 2009-12-01 16:45:18 ===
> I(<0.356.0>:ejabberd_listener:229) : (#Port<0.430>) Accepted connection
> {{127,0,0,1},64270} -> {{127,0,0,1},5222}
> =INFO REPORT==== 2009-12-01 16:45:18 ===
> D(<0.380.0>:ejabberd_receiver:320) : Received XML on stream =
> "<stream:stream xmlns:stream=\"
http://etherx.jabber.org/streams\"
> xmlns=\"jabber:client\" to=\"macintosh-4.local\">"
> =INFO REPORT==== 2009-12-01 16:45:18 ===
> D(<0.381.0>:ejabberd_c2s:1376) : Send XML on stream = "<?xml
> version='1.0'?><stream:stream xmlns='jabber:client'
> xmlns:stream='
http://etherx.jabber.org/streams' id='3167661546'
> from='macintosh-4.local' xml:lang='en'>"
> =INFO REPORT==== 2009-12-01 16:45:34 ===
> D(<0.380.0>:ejabberd_receiver:320) : Received XML on stream = "<iq
> xmlns=\"jabber:client\" type=\"get\" to=\"feeds.macintosh-4.local\"
> id=\"pubsub-396429316\" from=\"iw <at> macintosh-4.local\"><pubsub
> xmlns=\"
http://jabber.org/protocol/pubsub\"><subscriptions/></pubsub></iq>"
> =INFO REPORT==== 2009-12-01 16:45:34 ===
> D(<0.380.0>:shaper:61) : State: {maxrate,1000,0,1259685918498901}, Size=201
> M=100.5, I=15899.195
>
> =INFO REPORT==== 2009-12-01 16:45:34 ===
> D(<0.381.0>:ejabberd_c2s:1376) : Send XML on stream = "<iq
> from='macintosh-4.local' id='pubsub-396429316' type='error'><error
> code='503' type='cancel'><service-unavailable
> xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>"
>
>
>
> On Tue, Dec 1, 2009 at 6:16 PM, Pablo Polvorin
> <
pablo.polvorin <at> process-one.net> wrote:
>>
>> Hello Ian,
>> could you look if there is anything strange in the ejabberd's logs
>> between the info report at "2009-12-01 16:39:08" and the error at
>> "2009-12-01 16:45:34" ?.
>>
>> Specifically, it isn't your component disconnected for some reason?.
>>
>>
>> 2009/12/1 Ian Wilkinson <
the.ian.wilkinson <at> googlemail.com>:
>> > Hi,
>> > My apologies if this is the wrong list for posting the following.
>> > I'm currently doing discovery on the exmpp_component, specifically,
>> > around PubSub support.
>> > I have used the "Scalable XMPP bots" series
>> >
>> > (
http://www.process-one.net/en/blogs/article/scalable_xmpp_bots_with_erlang_and_exmpp_part_i/)
>> > to provide the early learning.
>> > From that, I produced an external component (modelled after the
>> > web_status_component), and
>> > included the service within the installed ejabberd configuration. I
>> > instrumented this component to log iq,
>> > message and presence packets.
>> > However, when I attempt to retrieve subscriptions from the component (
>> >
http://xmpp.org/extensions/xep-0060.html#entity-subscriptions), I see no
>> > logging from the
>> > component, and the ejabberd.log is indicating the service is
>> > unavailable.
>> > I'm including the shell session, ejabberd configuration, and
>> > ejabberd.log
>> > output.
>> > Have I made some dumb assumptions, or should I be seeing some initial
>> > logging
>> > from the external component I launched.
>> > many thanks,
>> > ian
>> >
>> > 1> hugin_feed_component:start_link().
>> > ...
>> > {ok,<0.69.0>}
>> > 2> Session = exmpp_session:start().
>> > <0.86.0>
>> > 3> Jid = exmpp_jid:make("iw", "macintosh-4.local").
>> > {jid,<<"iw <at> macintosh-4.local">>,<<"iw">>,
>> > <<"macintosh-4.local">>,undefined}
>> > 4> exmpp_session:auth_basic_digest(Session, Jid, "secret").
>> > ok
>> > 5> exmpp_session:connect_TCP(Session, "localhost", 5222).
>> > "3670992088"
>> > 6> Iq =
>> > exmpp_client_pubsub:get_subscriptions("feeds.macintosh-4.local").
>> > {xmlel,'jabber:client',[],iq,
>> > [{xmlattr,undefined,type,<<"get">>},
>> > {xmlattr,undefined,to,<<"feeds.macintosh-4.local">>},
>> > {xmlattr,undefined,id,<<"pubsub-396429316">>}],
>> > [{xmlel,'
http://jabber.org/protocol/pubsub',[],pubsub,[],
>> > [{xmlel,'
http://jabber.org/protocol/pubsub',[],
>> > subscriptions,[],[]}]}]}
>> > 7> Iq2 = exmpp_stanza:set_sender(Iq, Jid).
>> > {xmlel,'jabber:client',[],iq,
>> > [{xmlattr,undefined,type,<<"get">>},
>> > {xmlattr,undefined,to,<<"feeds.macintosh-4.local">>},
>> > {xmlattr,undefined,id,<<"pubsub-396429316">>},
>> > {xmlattr,undefined,from,<<"iw <at> macintosh-4.local">>}],
>> > [{xmlel,'
http://jabber.org/protocol/pubsub',[],pubsub,[],
>> > [{xmlel,'
http://jabber.org/protocol/pubsub',[],
>> > subscriptions,[],[]}]}]}
>> > 8> io:format("~s~n", [exmpp_stanza:to_list(Iq2)]).
>> > <iq type="get" to="feeds.macintosh-4.local" id="pubsub-396429316"
>> > from="iw <at> macintosh-4.local"><pubsub
>> > xmlns="
http://jabber.org/protocol/pubsub"><subscriptions/></pubsub></iq>
>> > ok
>> > 9> exmpp_session:send_packet(Session, Iq2).
>> > <<"pubsub-396429316">>
>> >
>> > From the ejabberd.cfg:
>> > {8889, ejabberd_service, [
>> > {access, all},
>> > {shaper_rule, fast},
>> > {ip, {127, 0, 0, 1}},
>> > {hosts, ["feeds.macintosh-4.local"],
>> > [{password, "secret"}]
>> > }
>> > ]
>> > },
>> >
>> > From the ejabberd.log:
>> > =INFO REPORT==== 2009-12-01 16:39:08 ===
>> > I(<0.362.0>:ejabberd_service:217) : Route registered for service
>> > "feeds.macintosh-4.local"
>> > ...
>> > =INFO REPORT==== 2009-12-01 16:45:34 ===
>> > D(<0.381.0>:ejabberd_c2s:1376) : Send XML on stream = "<iq
>> > from='macintosh-4.local' id='pubsub-396429316' type='error'><error
>> > code='503' type='cancel'><service-unavailable
>> > xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>"
>> >
>> > _______________________________________________
>> > ejabberd mailing list
>> >
ejabberd <at> jabber.ru
>> >
http://lists.jabber.ru/mailman/listinfo/ejabberd
>> >
>> >
>>
>>
>>
>> --
>> Pablo Polvorin
>> ProcessOne
>> _______________________________________________
>> ejabberd mailing list
>>
ejabberd <at> jabber.ru
>>
http://lists.jabber.ru/mailman/listinfo/ejabberd
>
>
> _______________________________________________
> ejabberd mailing list
>
ejabberd <at> jabber.ru
>
http://lists.jabber.ru/mailman/listinfo/ejabberd
>
>
--
Pablo Polvorin
ProcessOne
_______________________________________________
ejabberd mailing list
ejabberd <at> jabber.ruhttp://lists.jabber.ru/mailman/listinfo/ejabberd
The module ejabberd_router is not the cause of the problem. Neither is
it a slow client. It's not even mnesia. The problem is that the
filter_packet hook blocks ejabberd_router. If anything on that hook
ever gets slow the entire router queue will wait. It must be one of my
packet filters blocking the router and causing the pile-up.
I wondered if I could rewrite ejabberd_router:do_route/3 to dispatch
messages asynchronously. A scan of RFC 3920, XMPP Core, provides the
answer:
10. Server Rules for Handling XML Stanzas
Compliant server implementations MUST ensure in-order processing of
XML stanzas between any two entities.
Dang. I was hoping to keep the router going despite some packets
taking a long time to run through the filters but I can't do that by
simply spawning processes. Doing so would make it possible for some
messages to be delivered before other messages sent earlier.
End of story. Beginning of proposal. All invented while composing.
It would be possible to amend ejabberd_router so that it spawns new
processes to handle messages while honoring RFC 3920. The trick would
be to limit the spawning to one process per pair of entities. If the
router sent its messages to these other processes, which would then
run the packet_filter hook, then there would be no way to block the
router. The entity-pair routers would still be blocked by the hook but
the result would be a more robust system.
So should I code this up? 
RSS Feed