Jon Tara
2011-08-09 20:02:33 UTC
I've been experimenting with Jabber::HttpBinding::Client, and haven't
been having much luck. Is anybody using Jabber::HttpBinding::Client
successfully? Particularly with a MUC? If so, are there any examples you
can point to?
Some background: I'm developing a cross-platform mobile app for iPhone,
Android, etc. in Rhodes. For those unfamiliar, Rhodes is a Rails-like
development environment that allows mobile development in Ruby, using
each platform's native browser control (talking to an internal server)
for display. Rhodes uses Ruby 1.9.1p129.
For mobile use, I figured BOSH would be the best way to go. In theory,
it should be able to deal with connectivity dropouts without annoying
presence drops (the server's connection manager should avoid this) as
well as avoiding any firewall issues because it uses HTTP on port 80.
For testing, though, I've taken the Rhodes environment out of the
equation. I've been writing some simple command-line tests, which I've
tried in both Ruby 1.9.2-p290 and 1.8.7-p352. (I thought at first I had
some issues with a known Mutex.synchronize bug in 1.9.x so dropped-back
to 1.8.7, which should avoid that since it is an entirely different
threading model.)
HOWEVER, looking at the log, it sure looks like a Mutex.synchronize
issue! Is it possible that Mutex.synchronize has been this broken in
Ruby for this long??? There is a patch available for 1.9.2, I guess I
should try it... (I have siimilar MUC issues in the Rhodes environment
even when using a regular Jabber::Client, but not in command-line tests.
I am testing against ejabberd 2.1.8.
Two deficiencies I've noticed:
1. From what I understand of BOSH, it should deal well with loss of
connectivity. Now, I have to admit my test is rather crude: I disconnect
the network cable from my client machine for a period of time,
reconnect, and see if I still get messages at the client. And of course
I'm checking the log for recovery activity.
This has been a total failure with Jabber::HTTPBinding::Client.
On the other hand, Jabber::Reliable::Connection handles that situation
perfectly! The negatives, though, are that (with no connection manager
at the server to handle this) presence drops and is re-established. As
well, there is no way to gain control when it reconnects, so that the
client can re-join MUCs, etc. (But this could be done with a simple mod
to Jabber::Reliable::Connection.
Maybe this is just normal behaviour? I get the exception about 45
seconds after breaking the connection. I guess the client should catch
the timeout exception... Is this timing because that's how long it takes
2 HTTP sessions to timeout (20+20)? It does recover with no loss of
presence when I break the connection for less time, so maybe no problem
here, and I just need to fiddle with parameters to get the amount of
acceptable dropout time to a sufficiently large number for mobile use.
2. As long as the connection isn't broken, it seems to be acting as
expected. UNTIL... the client joins a MUC. At that point, the client
starts sending HTTP requests at a rapid rate - 2 seconds or less.
Eventually, the application will throw an exception. If the client never
joins a MUC, there is a new HTTP request every 20 seconds, as expected.
Here's what happens when I unplug the network cable:
----------------------------
D, [2011-08-09T12:43:47.484675 #5226] DEBUG -- : Debugging mode enabled.
W, [2011-08-09T12:43:47.484783 #5226] WARN -- : Warnings mode enabled.
D, [2011-08-09T12:43:47.485061 #5226] DEBUG -- : PEEPR: created client:
#<Jabber::HTTPBinding::Client:0x1012446c0 @pending_requests=0,
@send_lock=#<Mutex:0x101243ef0>, @keepalive_interval=60,
@exception_block=nil, @stanzacbs=#<Jabber::CallbackList:0x1012440f8
@list=[]>, @status=1, @http_requests=1, @tls=false,
@features_sem=#<Jabber::Semaphore:0x101243e00 @tickets=0,
@lock=#<Mutex:0x101243db0>, @cond=#<ConditionVariable:0x101243d88>>,
@wakeup_thread=nil, @presencecbs=#<Jabber::CallbackList:0x101244008
@list=[]>, @http_content_type="text/xml; charset=utf-8",
@features_timeout=10, @host=nil, @processing=0, @streamid=nil,
@send_buffer="", @jid=#<Jabber::JID:0x1012446e8 @domain="peepr.lan",
@resource="bosh_callbacks_muc_test.rb", @node="test2">,
@threadblocks=[], @lock=#<Mutex:0x101244198>,
@iqcbs=#<Jabber::CallbackList:0x101244058 @list=[]>, @http_hold=1,
@ssl_verifycb=nil, @parser_thread=nil,
@xmlcbs=#<Jabber::CallbackList:0x101244120 @list=[]>,
@allow_tls="constant", @tbcbmutex=#<Mutex:0x101243e78>, @last_send=Wed
Dec 31 16:00:00 -0800 1969, @use_ssl=false,
@messagecbs=#<Jabber::CallbackList:0x1012440a8 @list=[]>, @http_wait=20,
@ssl_capath=nil, @port=nil, @streamns="jabber:client", @fd=nil>
D, [2011-08-09T12:43:47.485890 #5226] DEBUG -- : HTTP REQUEST (1/1):
<body rid='1524' wait='20' secure='true' to='peepr.lan'
content='text/xml; charset=utf-8' hold='1'
xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:43:47.603653 #5226] DEBUG -- : HTTP RESPONSE (1/1):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'
sid='4c2bd914d65bf02865b05db0dc62454423ec4379' wait='20' requests='2'
inactivity='30' maxpause='120' polling='2' ver='1.8' from='peepr.lan'
secure='true' authid='173136017' xmlns:xmpp='urn:xmpp:xbosh'
xmlns:stream='http://etherx.jabber.org/streams'/>
D, [2011-08-09T12:43:47.604521 #5226] DEBUG -- : PEEPR: connected
D, [2011-08-09T12:43:47.605364 #5226] DEBUG -- : SENDING:
<iq id='2605' type='set' xmlns='jabber:client'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>0dc4545cc0ae54762d86d63c5a39dc3e4ad172c9</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq>
D, [2011-08-09T12:43:47.605771 #5226] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1525' sid='4c2bd914d65bf02865b05db0dc62454423ec4379'
xmlns='http://jabber.org/protocol/httpbind'><iq id='2605'
type='set'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>0dc4545cc0ae54762d86d63c5a39dc3e4ad172c9</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq></body>
D, [2011-08-09T12:43:47.712391 #5226] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><iq
xmlns='jabber:client' type='result' id='2605'/></body>
D, [2011-08-09T12:43:47.713268 #5226] DEBUG -- : RECEIVED:
<iq id='2605' type='result' xmlns='jabber:client'/>
D, [2011-08-09T12:43:47.713842 #5226] DEBUG -- : PEEPR: authorized
D, [2011-08-09T12:43:47.714123 #5226] DEBUG -- : SENDING:
<presence xmlns='jabber:client'/>
D, [2011-08-09T12:43:47.714352 #5226] DEBUG -- : PEEPR: Sent presence
D, [2011-08-09T12:43:49.606092 #5226] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1526' sid='4c2bd914d65bf02865b05db0dc62454423ec4379'
xmlns='http://jabber.org/protocol/httpbind'><presence/></body>
D, [2011-08-09T12:43:49.711540 #5226] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'/><presence
xmlns='jabber:client' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'>
<priority>5</priority>
<c xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' ext='cs ep-notify html'/>
<delay xmlns='urn:xmpp:delay' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
stamp='2011-08-09T18:43:52Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:43:52'/></presence></body>
D, [2011-08-09T12:43:49.713190 #5226] DEBUG -- : RECEIVED:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
D, [2011-08-09T12:43:49.713606 #5226] DEBUG -- : PROCESSING:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
(Jabber::Presence)
D, [2011-08-09T12:43:49.713679 #5226] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:43:49.713737 #5226] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:43:49.713988 #5226] DEBUG -- : RECEIVED:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence>
D, [2011-08-09T12:43:49.715825 #5226] DEBUG -- : PROCESSING:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence> (Jabber::Presence)
D, [2011-08-09T12:43:49.715918 #5226] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:43:49.715975 #5226] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:43:51.606785 #5226] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1527' sid='4c2bd914d65bf02865b05db0dc62454423ec4379'
xmlns='http://jabber.org/protocol/httpbind'></body>
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/timeout.rb:64:in
`rbuf_fill': execution expired (Timeout::Error)
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/protocol.rb:134:in
`rbuf_fill'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/protocol.rb:116:in
`readuntil'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/protocol.rb:126:in
`readline'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:2028:in
`read_status_line'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:2017:in
`read_new'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:1051:in
`request'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:163:in
`post'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:543:in
`start'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:440:in
`start'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:161:in
`post'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:208:in
`post_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:257:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:267:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:122:in
`ensure_one_pending_request'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:215:in
`post_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:257:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:267:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/stream.rb:375:in
`send'
from
/Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:100:in
`send_presence'
from
/Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:11:in
`initialize'
from
/Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:127:in `new'
from /Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:127
--------------------------------------
And here's part of the log for the second case (join a MUC):
D, [2011-08-09T12:21:21.176188 #5100] DEBUG -- : Debugging mode enabled.
W, [2011-08-09T12:21:21.176306 #5100] WARN -- : Warnings mode enabled.
D, [2011-08-09T12:21:21.176865 #5100] DEBUG -- : PEEPR: created client:
#<Jabber::HTTPBinding::Client:0x101244418 @pending_requests=0,
@send_lock=#<Mutex:0x101243e28>, @keepalive_interval=60,
@exception_block=nil, @stanzacbs=#<Jabber::CallbackList:0x101244030
@list=[]>, @status=1, @http_requests=1, @tls=false,
@features_sem=#<Jabber::Semaphore:0x101243d38 @tickets=0,
@lock=#<Mutex:0x101243ce8>, @cond=#<ConditionVariable:0x101243cc0>>,
@wakeup_thread=nil, @presencecbs=#<Jabber::CallbackList:0x101243e78
@list=[]>, @http_content_type="text/xml; charset=utf-8",
@features_timeout=10, @host=nil, @processing=0, @streamid=nil,
@send_buffer="", @jid=#<Jabber::JID:0x1012445a8 @domain="peepr.lan",
@resource="bosh_callbacks_muc_test.rb", @node="test2">,
@threadblocks=[], @lock=#<Mutex:0x1012440d0>,
@iqcbs=#<Jabber::CallbackList:0x101243f90 @list=[]>, @http_hold=1,
@ssl_verifycb=nil, @parser_thread=nil,
@xmlcbs=#<Jabber::CallbackList:0x101244058 @list=[]>,
@allow_tls="constant", @tbcbmutex=#<Mutex:0x101243db0>, @last_send=Wed
Dec 31 16:00:00 -0800 1969, @use_ssl=false,
@messagecbs=#<Jabber::CallbackList:0x101243fe0 @list=[]>, @http_wait=20,
@ssl_capath=nil, @port=nil, @streamns="jabber:client", @fd=nil>
D, [2011-08-09T12:21:21.177897 #5100] DEBUG -- : HTTP REQUEST (1/1):
<body rid='1705' wait='20' secure='true' to='peepr.lan'
content='text/xml; charset=utf-8' hold='1'
xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:21.284104 #5100] DEBUG -- : HTTP RESPONSE (1/1):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'
sid='59f2a3922885638cd0b19b2d6194dd19d35e721e' wait='20' requests='2'
inactivity='30' maxpause='120' polling='2' ver='1.8' from='peepr.lan'
secure='true' authid='2863231041' xmlns:xmpp='urn:xmpp:xbosh'
xmlns:stream='http://etherx.jabber.org/streams'/>
D, [2011-08-09T12:21:21.284953 #5100] DEBUG -- : PEEPR: connected
D, [2011-08-09T12:21:21.285854 #5100] DEBUG -- : SENDING:
<iq id='2548' type='set' xmlns='jabber:client'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>5e60209e28b761d097c208e4783361b83e98894f</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq>
D, [2011-08-09T12:21:21.286152 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1706' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'><iq id='2548'
type='set'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>5e60209e28b761d097c208e4783361b83e98894f</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq></body>
D, [2011-08-09T12:21:21.391060 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><iq
xmlns='jabber:client' type='result' id='2548'/></body>
D, [2011-08-09T12:21:21.392094 #5100] DEBUG -- : RECEIVED:
<iq id='2548' type='result' xmlns='jabber:client'/>
D, [2011-08-09T12:21:21.392900 #5100] DEBUG -- : PEEPR: authorized
D, [2011-08-09T12:21:21.393055 #5100] DEBUG -- : PEEPR: created MUC client
D, [2011-08-09T12:21:21.393774 #5100] DEBUG -- : SENDING:
<presence to='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT' xmlns='jabber:client'><x
xmlns='http://jabber.org/protocol/muc'/></presence>
D, [2011-08-09T12:21:23.286693 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1707' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'><presence
to='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'><x
xmlns='http://jabber.org/protocol/muc'/></presence></body>
D, [2011-08-09T12:21:23.393187 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
xml:lang='en'><priority>5</priority><c
xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' ext='cs ep-notify html'/><x
xmlns='http://jabber.org/protocol/muc#user'><item affiliation='owner'
role='moderator'/></x></presence><presence xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'><x
xmlns='http://jabber.org/protocol/muc#user'><item affiliation='none'
role='participant'/></x></presence><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat'><body>I'm posting to the room from the Peepr app
at Tue Aug 09 11:45:13 -0700 2011.!</body><delay xmlns='urn:xmpp:delay'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:44:59Z'></delay><x
xmlns='jabber:x:delay' stamp='20110809T18:44:59'/></message><message
xmlns='jabber:client' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac1a'>
<body>room 1</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:26Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:26'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac2a'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:27Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:27'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac3a'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:30Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:30'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac4a'>
<body>room 4</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:32Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:32'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac5a'>
<body>room 5</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:34Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:34'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat'><body>I'm posting to the room from the Peepr app
at Tue Aug 09 11:45:55 -0700 2011.!</body><delay xmlns='urn:xmpp:delay'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:41Z'></delay><x
xmlns='jabber:x:delay' stamp='20110809T18:45:41'/></message><message
xmlns='jabber:client' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aad8a'>
<body>room</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T19:04:41Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T19:04:41'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
type='groupchat'><subject>No special topic</subject><body>linux-box has
set the subject to: No special topic</body></message></body>
D, [2011-08-09T12:21:23.400880 #5100] DEBUG -- : RECEIVED:
<presence from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'><priority>5</priority><c ext='cs ep-notify html'
node='http://psi-im.org/caps' ver='caps-b75d8d2b25'
xmlns='http://jabber.org/protocol/caps'/><x
xmlns='http://jabber.org/protocol/muc#user'><item role='moderator'
affiliation='owner'/></x></presence>
D, [2011-08-09T12:21:23.402477 #5100] DEBUG -- : PROCESSING:
<presence from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'><priority>5</priority><c ext='cs ep-notify html'
node='http://psi-im.org/caps' ver='caps-b75d8d2b25'
xmlns='http://jabber.org/protocol/caps'/><x
xmlns='http://jabber.org/protocol/muc#user'><item role='moderator'
affiliation='owner'/></x></presence> (Jabber::Presence)
D, [2011-08-09T12:21:23.402537 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.402587 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.403113 #5100] DEBUG -- : RECEIVED:
<presence from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'><x
xmlns='http://jabber.org/protocol/muc#user'><item role='participant'
affiliation='none'/></x></presence>
D, [2011-08-09T12:21:23.405106 #5100] DEBUG -- : PEEPR: Room join else
D, [2011-08-09T12:21:23.405675 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:13 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:44:59Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:44:59'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.405834 #5100] DEBUG -- : PEEPR: Joined room
D, [2011-08-09T12:21:23.407390 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:13 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:44:59Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:44:59'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.407530 #5100] DEBUG -- : PEEPR: Room join ensure
D, [2011-08-09T12:21:23.407692 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.407962 #5100] DEBUG -- : SENDING:
<presence xmlns='jabber:client'/>
D, [2011-08-09T12:21:23.408069 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.408358 #5100] DEBUG -- : PEEPR: Sent presence
D, [2011-08-09T12:21:23.409915 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac1a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 1</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:26Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:26'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.411602 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac1a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 1</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:26Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:26'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.411662 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.411713 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.414596 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac2a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:27Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:27'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.419674 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac2a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:27Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:27'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.419806 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.419859 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.421910 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac3a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:30Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:30'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.423455 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac3a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:30Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:30'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.423523 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.423575 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.424811 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac4a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 4</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:32Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:32'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.426548 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac4a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 4</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:32Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:32'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.426629 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.426681 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.428028 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac5a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 5</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:34Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:34'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.443439 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac5a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 5</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:34Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:34'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.443539 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.443594 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.444713 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:55 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:41'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.445809 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:55 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:41'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.445869 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.445920 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.446966 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aad8a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T19:04:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T19:04:41'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.448346 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aad8a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T19:04:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T19:04:41'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.448403 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.448453 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.449405 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xmlns='jabber:client'><subject>No special topic</subject><body>linux-box
has set the subject to: No special topic</body></message>
D, [2011-08-09T12:21:23.449878 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xmlns='jabber:client'><subject>No special topic</subject><body>linux-box
has set the subject to: No special topic</body></message> (Jabber::Message)
D, [2011-08-09T12:21:23.449932 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.449982 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:25.287241 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1708' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'><presence/></body>
D, [2011-08-09T12:21:25.396211 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'/><presence
xmlns='jabber:client' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'>
<priority>5</priority>
<c xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' ext='cs ep-notify html'/>
<delay xmlns='urn:xmpp:delay' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
stamp='2011-08-09T18:43:52Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:43:52'/></presence></body>
D, [2011-08-09T12:21:25.397835 #5100] DEBUG -- : RECEIVED:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
D, [2011-08-09T12:21:25.398244 #5100] DEBUG -- : PROCESSING:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
(Jabber::Presence)
D, [2011-08-09T12:21:25.398310 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:25.398367 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:25.398679 #5100] DEBUG -- : RECEIVED:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence>
D, [2011-08-09T12:21:25.400443 #5100] DEBUG -- : PROCESSING:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence> (Jabber::Presence)
D, [2011-08-09T12:21:25.400529 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:25.400580 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:27.287738 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1709' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:29.288857 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1710' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:29.395418 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:31.289217 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1711' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:31.395353 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:33.289648 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1712' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:33.396314 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:35.290045 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1713' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:36.285330 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:37.290568 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1714' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:37.396555 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:39.291167 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1715' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:39.397672 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:41.291700 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1716' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:41.397658 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:43.292120 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1717' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:43.397618 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:45.292775 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1718' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:45.400186 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
been having much luck. Is anybody using Jabber::HttpBinding::Client
successfully? Particularly with a MUC? If so, are there any examples you
can point to?
Some background: I'm developing a cross-platform mobile app for iPhone,
Android, etc. in Rhodes. For those unfamiliar, Rhodes is a Rails-like
development environment that allows mobile development in Ruby, using
each platform's native browser control (talking to an internal server)
for display. Rhodes uses Ruby 1.9.1p129.
For mobile use, I figured BOSH would be the best way to go. In theory,
it should be able to deal with connectivity dropouts without annoying
presence drops (the server's connection manager should avoid this) as
well as avoiding any firewall issues because it uses HTTP on port 80.
For testing, though, I've taken the Rhodes environment out of the
equation. I've been writing some simple command-line tests, which I've
tried in both Ruby 1.9.2-p290 and 1.8.7-p352. (I thought at first I had
some issues with a known Mutex.synchronize bug in 1.9.x so dropped-back
to 1.8.7, which should avoid that since it is an entirely different
threading model.)
HOWEVER, looking at the log, it sure looks like a Mutex.synchronize
issue! Is it possible that Mutex.synchronize has been this broken in
Ruby for this long??? There is a patch available for 1.9.2, I guess I
should try it... (I have siimilar MUC issues in the Rhodes environment
even when using a regular Jabber::Client, but not in command-line tests.
I am testing against ejabberd 2.1.8.
Two deficiencies I've noticed:
1. From what I understand of BOSH, it should deal well with loss of
connectivity. Now, I have to admit my test is rather crude: I disconnect
the network cable from my client machine for a period of time,
reconnect, and see if I still get messages at the client. And of course
I'm checking the log for recovery activity.
This has been a total failure with Jabber::HTTPBinding::Client.
On the other hand, Jabber::Reliable::Connection handles that situation
perfectly! The negatives, though, are that (with no connection manager
at the server to handle this) presence drops and is re-established. As
well, there is no way to gain control when it reconnects, so that the
client can re-join MUCs, etc. (But this could be done with a simple mod
to Jabber::Reliable::Connection.
Maybe this is just normal behaviour? I get the exception about 45
seconds after breaking the connection. I guess the client should catch
the timeout exception... Is this timing because that's how long it takes
2 HTTP sessions to timeout (20+20)? It does recover with no loss of
presence when I break the connection for less time, so maybe no problem
here, and I just need to fiddle with parameters to get the amount of
acceptable dropout time to a sufficiently large number for mobile use.
2. As long as the connection isn't broken, it seems to be acting as
expected. UNTIL... the client joins a MUC. At that point, the client
starts sending HTTP requests at a rapid rate - 2 seconds or less.
Eventually, the application will throw an exception. If the client never
joins a MUC, there is a new HTTP request every 20 seconds, as expected.
Here's what happens when I unplug the network cable:
----------------------------
D, [2011-08-09T12:43:47.484675 #5226] DEBUG -- : Debugging mode enabled.
W, [2011-08-09T12:43:47.484783 #5226] WARN -- : Warnings mode enabled.
D, [2011-08-09T12:43:47.485061 #5226] DEBUG -- : PEEPR: created client:
#<Jabber::HTTPBinding::Client:0x1012446c0 @pending_requests=0,
@send_lock=#<Mutex:0x101243ef0>, @keepalive_interval=60,
@exception_block=nil, @stanzacbs=#<Jabber::CallbackList:0x1012440f8
@list=[]>, @status=1, @http_requests=1, @tls=false,
@features_sem=#<Jabber::Semaphore:0x101243e00 @tickets=0,
@lock=#<Mutex:0x101243db0>, @cond=#<ConditionVariable:0x101243d88>>,
@wakeup_thread=nil, @presencecbs=#<Jabber::CallbackList:0x101244008
@list=[]>, @http_content_type="text/xml; charset=utf-8",
@features_timeout=10, @host=nil, @processing=0, @streamid=nil,
@send_buffer="", @jid=#<Jabber::JID:0x1012446e8 @domain="peepr.lan",
@resource="bosh_callbacks_muc_test.rb", @node="test2">,
@threadblocks=[], @lock=#<Mutex:0x101244198>,
@iqcbs=#<Jabber::CallbackList:0x101244058 @list=[]>, @http_hold=1,
@ssl_verifycb=nil, @parser_thread=nil,
@xmlcbs=#<Jabber::CallbackList:0x101244120 @list=[]>,
@allow_tls="constant", @tbcbmutex=#<Mutex:0x101243e78>, @last_send=Wed
Dec 31 16:00:00 -0800 1969, @use_ssl=false,
@messagecbs=#<Jabber::CallbackList:0x1012440a8 @list=[]>, @http_wait=20,
@ssl_capath=nil, @port=nil, @streamns="jabber:client", @fd=nil>
D, [2011-08-09T12:43:47.485890 #5226] DEBUG -- : HTTP REQUEST (1/1):
<body rid='1524' wait='20' secure='true' to='peepr.lan'
content='text/xml; charset=utf-8' hold='1'
xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:43:47.603653 #5226] DEBUG -- : HTTP RESPONSE (1/1):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'
sid='4c2bd914d65bf02865b05db0dc62454423ec4379' wait='20' requests='2'
inactivity='30' maxpause='120' polling='2' ver='1.8' from='peepr.lan'
secure='true' authid='173136017' xmlns:xmpp='urn:xmpp:xbosh'
xmlns:stream='http://etherx.jabber.org/streams'/>
D, [2011-08-09T12:43:47.604521 #5226] DEBUG -- : PEEPR: connected
D, [2011-08-09T12:43:47.605364 #5226] DEBUG -- : SENDING:
<iq id='2605' type='set' xmlns='jabber:client'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>0dc4545cc0ae54762d86d63c5a39dc3e4ad172c9</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq>
D, [2011-08-09T12:43:47.605771 #5226] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1525' sid='4c2bd914d65bf02865b05db0dc62454423ec4379'
xmlns='http://jabber.org/protocol/httpbind'><iq id='2605'
type='set'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>0dc4545cc0ae54762d86d63c5a39dc3e4ad172c9</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq></body>
D, [2011-08-09T12:43:47.712391 #5226] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><iq
xmlns='jabber:client' type='result' id='2605'/></body>
D, [2011-08-09T12:43:47.713268 #5226] DEBUG -- : RECEIVED:
<iq id='2605' type='result' xmlns='jabber:client'/>
D, [2011-08-09T12:43:47.713842 #5226] DEBUG -- : PEEPR: authorized
D, [2011-08-09T12:43:47.714123 #5226] DEBUG -- : SENDING:
<presence xmlns='jabber:client'/>
D, [2011-08-09T12:43:47.714352 #5226] DEBUG -- : PEEPR: Sent presence
D, [2011-08-09T12:43:49.606092 #5226] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1526' sid='4c2bd914d65bf02865b05db0dc62454423ec4379'
xmlns='http://jabber.org/protocol/httpbind'><presence/></body>
D, [2011-08-09T12:43:49.711540 #5226] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'/><presence
xmlns='jabber:client' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'>
<priority>5</priority>
<c xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' ext='cs ep-notify html'/>
<delay xmlns='urn:xmpp:delay' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
stamp='2011-08-09T18:43:52Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:43:52'/></presence></body>
D, [2011-08-09T12:43:49.713190 #5226] DEBUG -- : RECEIVED:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
D, [2011-08-09T12:43:49.713606 #5226] DEBUG -- : PROCESSING:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
(Jabber::Presence)
D, [2011-08-09T12:43:49.713679 #5226] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:43:49.713737 #5226] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:43:49.713988 #5226] DEBUG -- : RECEIVED:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence>
D, [2011-08-09T12:43:49.715825 #5226] DEBUG -- : PROCESSING:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence> (Jabber::Presence)
D, [2011-08-09T12:43:49.715918 #5226] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:43:49.715975 #5226] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:43:51.606785 #5226] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1527' sid='4c2bd914d65bf02865b05db0dc62454423ec4379'
xmlns='http://jabber.org/protocol/httpbind'></body>
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/timeout.rb:64:in
`rbuf_fill': execution expired (Timeout::Error)
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/protocol.rb:134:in
`rbuf_fill'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/protocol.rb:116:in
`readuntil'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/protocol.rb:126:in
`readline'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:2028:in
`read_status_line'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:2017:in
`read_new'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:1051:in
`request'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:163:in
`post'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:543:in
`start'
from
/Users/jon/.rvm/rubies/ruby-1.8.7-p352/lib/ruby/1.8/net/http.rb:440:in
`start'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:161:in
`post'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:208:in
`post_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:257:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:267:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:122:in
`ensure_one_pending_request'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:215:in
`post_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:257:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:255:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:267:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`initialize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`new'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:261:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`synchronize'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/httpbinding/client.rb:244:in
`send_data'
from
/Users/jon/.rvm/gems/ruby-1.8.7-p352/gems/xmpp4r-0.5/lib/xmpp4r/stream.rb:375:in
`send'
from
/Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:100:in
`send_presence'
from
/Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:11:in
`initialize'
from
/Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:127:in `new'
from /Users/jon/workspace/jabbertest/bosh_callbacks_muc_test.rb:127
--------------------------------------
And here's part of the log for the second case (join a MUC):
D, [2011-08-09T12:21:21.176188 #5100] DEBUG -- : Debugging mode enabled.
W, [2011-08-09T12:21:21.176306 #5100] WARN -- : Warnings mode enabled.
D, [2011-08-09T12:21:21.176865 #5100] DEBUG -- : PEEPR: created client:
#<Jabber::HTTPBinding::Client:0x101244418 @pending_requests=0,
@send_lock=#<Mutex:0x101243e28>, @keepalive_interval=60,
@exception_block=nil, @stanzacbs=#<Jabber::CallbackList:0x101244030
@list=[]>, @status=1, @http_requests=1, @tls=false,
@features_sem=#<Jabber::Semaphore:0x101243d38 @tickets=0,
@lock=#<Mutex:0x101243ce8>, @cond=#<ConditionVariable:0x101243cc0>>,
@wakeup_thread=nil, @presencecbs=#<Jabber::CallbackList:0x101243e78
@list=[]>, @http_content_type="text/xml; charset=utf-8",
@features_timeout=10, @host=nil, @processing=0, @streamid=nil,
@send_buffer="", @jid=#<Jabber::JID:0x1012445a8 @domain="peepr.lan",
@resource="bosh_callbacks_muc_test.rb", @node="test2">,
@threadblocks=[], @lock=#<Mutex:0x1012440d0>,
@iqcbs=#<Jabber::CallbackList:0x101243f90 @list=[]>, @http_hold=1,
@ssl_verifycb=nil, @parser_thread=nil,
@xmlcbs=#<Jabber::CallbackList:0x101244058 @list=[]>,
@allow_tls="constant", @tbcbmutex=#<Mutex:0x101243db0>, @last_send=Wed
Dec 31 16:00:00 -0800 1969, @use_ssl=false,
@messagecbs=#<Jabber::CallbackList:0x101243fe0 @list=[]>, @http_wait=20,
@ssl_capath=nil, @port=nil, @streamns="jabber:client", @fd=nil>
D, [2011-08-09T12:21:21.177897 #5100] DEBUG -- : HTTP REQUEST (1/1):
<body rid='1705' wait='20' secure='true' to='peepr.lan'
content='text/xml; charset=utf-8' hold='1'
xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:21.284104 #5100] DEBUG -- : HTTP RESPONSE (1/1):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'
sid='59f2a3922885638cd0b19b2d6194dd19d35e721e' wait='20' requests='2'
inactivity='30' maxpause='120' polling='2' ver='1.8' from='peepr.lan'
secure='true' authid='2863231041' xmlns:xmpp='urn:xmpp:xbosh'
xmlns:stream='http://etherx.jabber.org/streams'/>
D, [2011-08-09T12:21:21.284953 #5100] DEBUG -- : PEEPR: connected
D, [2011-08-09T12:21:21.285854 #5100] DEBUG -- : SENDING:
<iq id='2548' type='set' xmlns='jabber:client'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>5e60209e28b761d097c208e4783361b83e98894f</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq>
D, [2011-08-09T12:21:21.286152 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1706' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'><iq id='2548'
type='set'><query
xmlns='jabber:iq:auth'><username>test2</username><digest>5e60209e28b761d097c208e4783361b83e98894f</digest><resource>bosh_callbacks_muc_test.rb</resource></query></iq></body>
D, [2011-08-09T12:21:21.391060 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><iq
xmlns='jabber:client' type='result' id='2548'/></body>
D, [2011-08-09T12:21:21.392094 #5100] DEBUG -- : RECEIVED:
<iq id='2548' type='result' xmlns='jabber:client'/>
D, [2011-08-09T12:21:21.392900 #5100] DEBUG -- : PEEPR: authorized
D, [2011-08-09T12:21:21.393055 #5100] DEBUG -- : PEEPR: created MUC client
D, [2011-08-09T12:21:21.393774 #5100] DEBUG -- : SENDING:
<presence to='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT' xmlns='jabber:client'><x
xmlns='http://jabber.org/protocol/muc'/></presence>
D, [2011-08-09T12:21:23.286693 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1707' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'><presence
to='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'><x
xmlns='http://jabber.org/protocol/muc'/></presence></body>
D, [2011-08-09T12:21:23.393187 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
xml:lang='en'><priority>5</priority><c
xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' ext='cs ep-notify html'/><x
xmlns='http://jabber.org/protocol/muc#user'><item affiliation='owner'
role='moderator'/></x></presence><presence xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'><x
xmlns='http://jabber.org/protocol/muc#user'><item affiliation='none'
role='participant'/></x></presence><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat'><body>I'm posting to the room from the Peepr app
at Tue Aug 09 11:45:13 -0700 2011.!</body><delay xmlns='urn:xmpp:delay'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:44:59Z'></delay><x
xmlns='jabber:x:delay' stamp='20110809T18:44:59'/></message><message
xmlns='jabber:client' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac1a'>
<body>room 1</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:26Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:26'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac2a'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:27Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:27'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac3a'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:30Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:30'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac4a'>
<body>room 4</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:32Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:32'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aac5a'>
<body>room 5</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T18:45:34Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:45:34'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat'><body>I'm posting to the room from the Peepr app
at Tue Aug 09 11:45:55 -0700 2011.!</body><delay xmlns='urn:xmpp:delay'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:41Z'></delay><x
xmlns='jabber:x:delay' stamp='20110809T18:45:41'/></message><message
xmlns='jabber:client' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
type='groupchat' id='aad8a'>
<body>room</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay xmlns='urn:xmpp:delay' from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
stamp='2011-08-09T19:04:41Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T19:04:41'/></message><message xmlns='jabber:client'
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
type='groupchat'><subject>No special topic</subject><body>linux-box has
set the subject to: No special topic</body></message></body>
D, [2011-08-09T12:21:23.400880 #5100] DEBUG -- : RECEIVED:
<presence from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'><priority>5</priority><c ext='cs ep-notify html'
node='http://psi-im.org/caps' ver='caps-b75d8d2b25'
xmlns='http://jabber.org/protocol/caps'/><x
xmlns='http://jabber.org/protocol/muc#user'><item role='moderator'
affiliation='owner'/></x></presence>
D, [2011-08-09T12:21:23.402477 #5100] DEBUG -- : PROCESSING:
<presence from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'><priority>5</priority><c ext='cs ep-notify html'
node='http://psi-im.org/caps' ver='caps-b75d8d2b25'
xmlns='http://jabber.org/protocol/caps'/><x
xmlns='http://jabber.org/protocol/muc#user'><item role='moderator'
affiliation='owner'/></x></presence> (Jabber::Presence)
D, [2011-08-09T12:21:23.402537 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.402587 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.403113 #5100] DEBUG -- : RECEIVED:
<presence from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'><x
xmlns='http://jabber.org/protocol/muc#user'><item role='participant'
affiliation='none'/></x></presence>
D, [2011-08-09T12:21:23.405106 #5100] DEBUG -- : PEEPR: Room join else
D, [2011-08-09T12:21:23.405675 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:13 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:44:59Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:44:59'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.405834 #5100] DEBUG -- : PEEPR: Joined room
D, [2011-08-09T12:21:23.407390 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:13 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:44:59Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:44:59'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.407530 #5100] DEBUG -- : PEEPR: Room join ensure
D, [2011-08-09T12:21:23.407692 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.407962 #5100] DEBUG -- : SENDING:
<presence xmlns='jabber:client'/>
D, [2011-08-09T12:21:23.408069 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.408358 #5100] DEBUG -- : PEEPR: Sent presence
D, [2011-08-09T12:21:23.409915 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac1a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 1</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:26Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:26'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.411602 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac1a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 1</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:26Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:26'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.411662 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.411713 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.414596 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac2a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:27Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:27'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.419674 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac2a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:27Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:27'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.419806 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.419859 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.421910 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac3a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:30Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:30'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.423455 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac3a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 2</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:30Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:30'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.423523 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.423575 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.424811 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac4a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 4</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:32Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:32'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.426548 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac4a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 4</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:32Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:32'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.426629 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.426681 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.428028 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac5a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 5</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:34Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:34'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.443439 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aac5a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room 5</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:34Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:34'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.443539 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.443594 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.444713 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:55 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:41'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.445809 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/JT'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xml:lang='en' xmlns='jabber:client'><body>I'm posting to the room
from the Peepr app at Tue Aug 09 11:45:55 -0700 2011.!</body><delay
from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T18:45:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:45:41'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.445869 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.445920 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.446966 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aad8a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T19:04:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T19:04:41'
xmlns='jabber:x:delay'/></message>
D, [2011-08-09T12:21:23.448346 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org/linux-box'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' id='aad8a'
type='groupchat' xml:lang='en' xmlns='jabber:client'>
<body>room</body>
<nick xmlns='http://jabber.org/protocol/nick'>JT-lb</nick>
<delay from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org' stamp='2011-08-09T19:04:41Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T19:04:41'
xmlns='jabber:x:delay'/></message> (Jabber::Message)
D, [2011-08-09T12:21:23.448403 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.448453 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:23.449405 #5100] DEBUG -- : RECEIVED:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xmlns='jabber:client'><subject>No special topic</subject><body>linux-box
has set the subject to: No special topic</body></message>
D, [2011-08-09T12:21:23.449878 #5100] DEBUG -- : PROCESSING:
<message from='33-8PHf0o9tX6c4lrnCc7/mB/***@public.gmane.org'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' type='groupchat'
xmlns='jabber:client'><subject>No special topic</subject><body>linux-box
has set the subject to: No special topic</body></message> (Jabber::Message)
D, [2011-08-09T12:21:23.449932 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:23.449982 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:25.287241 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1708' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'><presence/></body>
D, [2011-08-09T12:21:25.396211 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'><presence
xmlns='jabber:client' from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'/><presence
xmlns='jabber:client' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'>
<priority>5</priority>
<c xmlns='http://jabber.org/protocol/caps' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' ext='cs ep-notify html'/>
<delay xmlns='urn:xmpp:delay' from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
stamp='2011-08-09T18:43:52Z'></delay><x xmlns='jabber:x:delay'
stamp='20110809T18:43:52'/></presence></body>
D, [2011-08-09T12:21:25.397835 #5100] DEBUG -- : RECEIVED:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
D, [2011-08-09T12:21:25.398244 #5100] DEBUG -- : PROCESSING:
<presence from='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xmlns='jabber:client'/>
(Jabber::Presence)
D, [2011-08-09T12:21:25.398310 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:25.398367 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:25.398679 #5100] DEBUG -- : RECEIVED:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence>
D, [2011-08-09T12:21:25.400443 #5100] DEBUG -- : PROCESSING:
<presence from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus'
to='test2-CAX3S4KgTkn/***@public.gmane.org/bosh_callbacks_muc_test.rb' xml:lang='en'
xmlns='jabber:client'>
<priority>5</priority>
<c ext='cs ep-notify html' node='http://psi-im.org/caps'
ver='caps-b75d8d2b25' xmlns='http://jabber.org/protocol/caps'/>
<delay from='test1-CAX3S4KgTkn/***@public.gmane.org/colossus' stamp='2011-08-09T18:43:52Z'
xmlns='urn:xmpp:delay'/><x stamp='20110809T18:43:52'
xmlns='jabber:x:delay'/></presence> (Jabber::Presence)
D, [2011-08-09T12:21:25.400529 #5100] DEBUG -- : TRYING stanzacbs...
D, [2011-08-09T12:21:25.400580 #5100] DEBUG -- : TRYING
message/iq/presence/cbs...
D, [2011-08-09T12:21:27.287738 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1709' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:29.288857 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1710' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:29.395418 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:31.289217 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1711' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:31.395353 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:33.289648 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1712' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:33.396314 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:35.290045 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1713' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:36.285330 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:37.290568 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1714' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:37.396555 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:39.291167 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1715' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:39.397672 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:41.291700 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1716' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:41.397658 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:43.292120 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1717' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:43.397618 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>
D, [2011-08-09T12:21:45.292775 #5100] DEBUG -- : HTTP REQUEST (2/2):
<body rid='1718' sid='59f2a3922885638cd0b19b2d6194dd19d35e721e'
xmlns='http://jabber.org/protocol/httpbind'></body>
D, [2011-08-09T12:21:45.400186 #5100] DEBUG -- : HTTP RESPONSE (2/2):
Net::HTTPOK
<body xmlns='http://jabber.org/protocol/httpbind'/>