echo.rb shows error, stacktrace after upgrading to 0.8.0 #103
Comments
|
That stacktrace is missing an actual exception at the top. Are you sure that is the full output? Could you try running the script with -D to get a full debug log? |
|
Yes, I tried putting the -D and I got a lot more information. I saw an error iq of type wait just before it output the stacktrace. I assume |
|
Uninstalled blather -v 0.8.0. Using 0.7.1, it looked like the messages exchanged were different. Do I need to configure ejabberd differently for 0.8.0 to work? |
|
Ok, looks like something funny is going on with ejabberd. Can you post your ejabberd logs? |
|
Also, if you're seeing 0.8.0 behave differently, please post comparative logs. |
|
OK. Here's the debug output with blather 0.7.1. It successfully connected. Let me try to get the ejabberd log as well. Thanks for helping. |
|
It seems 0.8.0 is trying to use in-band registration. That's as specific as I can be from a cursory glance. I'll do some further debugging later. |
|
The =INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.254.0>:ejabberd_captcha:432) : The option captcha_cmd is not configured, but some module wants to use the CAPTCHA feature.
=INFO REPORT==== 2012-08-20 22:54:31 ===
I(<0.37.0>:ejabberd_rdbms:37) : ejabberd has not been compiled with relational database support. Skipping database startup.
=INFO REPORT==== 2012-08-20 22:54:31 ===
I(<0.37.0>:cyrsasl_digest:44) : FQDN used to check DIGEST-MD5 SASL authentication: "node.testsite.net"
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:175) : pubsub init "node" [{access_createnode,
pubsub_createnode},
{ignore_pep_from_offline,
true},
{last_item_cache,false},
{plugins,
["flat","hometree",
"pep"]}]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:258) : ** tree plugin is nodetree_tree
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:262) : ** PEP Mapping : []
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:269) : ** init flat plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:269) : ** init hometree plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:269) : ** init pep plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3811) : node_call "hometree" node_to_path [<<"/home">>]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3811) : node_call "hometree" path_to_node [[]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3811) : node_call "hometree" create_node_permission ["pubsub.node",
"node",
<<"/home">>,
<<>>,
{jid,
[],
"pubsub.node",
[],
[],
"pubsub.node",
[]},
all]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3798) : tree_call "pubsub.node" create_node ["pubsub.node",
<<"/home">>,
"hometree",
{jid,[],
"pubsub.node",
[],[],
"pubsub.node",
[]},
[{deliver_payloads,
true},
{notify_config,
false},
{notify_delete,
false},
{notify_retract,
true},
{purge_offline,
false},
{persist_items,
true},
{max_items,
10},
{subscribe,
true},
{access_model,
open},
{roster_groups_allowed,
[]},
{publish_model,
publishers},
{notification_type,
headline},
{max_payload_size,
60000},
{send_last_published_item,
on_sub_and_presence},
{deliver_notifications,
true},
{presence_based_delivery,
false}],
[]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3811) : node_call "hometree" node_to_path [<<"/home/node">>]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3811) : node_call "hometree" path_to_node [["home"]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3811) : node_call "hometree" create_node_permission ["pubsub.node",
"node",
<<"/home/node">>,
<<"/home">>,
{jid,
[],
"pubsub.node",
[],
[],
"pubsub.node",
[]},
all]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.310.0>:mod_pubsub:3798) : tree_call "pubsub.node" create_node ["pubsub.node",
<<"/home/node">>,
"hometree",
{jid,[],
"pubsub.node",
[],[],
"pubsub.node",
[]},
[{deliver_payloads,
true},
{notify_config,
false},
{notify_delete,
false},
{notify_retract,
true},
{purge_offline,
false},
{persist_items,
true},
{max_items,
10},
{subscribe,
true},
{access_model,
open},
{roster_groups_allowed,
[]},
{publish_model,
publishers},
{notification_type,
headline},
{max_payload_size,
60000},
{send_last_published_item,
on_sub_and_presence},
{deliver_notifications,
true},
{presence_based_delivery,
false}],
[<<"/home">>]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:175) : pubsub init "loverstoo.com" [{access_createnode,
pubsub_createnode},
{ignore_pep_from_offline,
true},
{last_item_cache,
false},
{plugins,
["flat",
"hometree",
"pep"]}]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:258) : ** tree plugin is nodetree_tree
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:262) : ** PEP Mapping : []
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:269) : ** init flat plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:269) : ** init hometree plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:269) : ** init pep plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3811) : node_call "hometree" node_to_path [<<"/home">>]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3811) : node_call "hometree" path_to_node [[]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3811) : node_call "hometree" create_node_permission ["pubsub.loverstoo.com",
"loverstoo.com",
<<"/home">>,
<<>>,
{jid,
[],
"pubsub.loverstoo.com",
[],
[],
"pubsub.loverstoo.com",
[]},
all]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3798) : tree_call "pubsub.loverstoo.com" create_node ["pubsub.loverstoo.com",
<<"/home">>,
"hometree",
{jid,
[],
"pubsub.loverstoo.com",
[],
[],
"pubsub.loverstoo.com",
[]},
[{deliver_payloads,
true},
{notify_config,
false},
{notify_delete,
false},
{notify_retract,
true},
{purge_offline,
false},
{persist_items,
true},
{max_items,
10},
{subscribe,
true},
{access_model,
open},
{roster_groups_allowed,
[]},
{publish_model,
publishers},
{notification_type,
headline},
{max_payload_size,
60000},
{send_last_published_item,
on_sub_and_presence},
{deliver_notifications,
true},
{presence_based_delivery,
false}],
[]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3811) : node_call "hometree" node_to_path [<<"/home/loverstoo.com">>]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3811) : node_call "hometree" path_to_node [["home"]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3811) : node_call "hometree" create_node_permission ["pubsub.loverstoo.com",
"loverstoo.com",
<<"/home/loverstoo.com">>,
<<"/home">>,
{jid,
[],
"pubsub.loverstoo.com",
[],
[],
"pubsub.loverstoo.com",
[]},
all]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.395.0>:mod_pubsub:3798) : tree_call "pubsub.loverstoo.com" create_node ["pubsub.loverstoo.com",
<<"/home/loverstoo.com">>,
"hometree",
{jid,
[],
"pubsub.loverstoo.com",
[],
[],
"pubsub.loverstoo.com",
[]},
[{deliver_payloads,
true},
{notify_config,
false},
{notify_delete,
false},
{notify_retract,
true},
{purge_offline,
false},
{persist_items,
true},
{max_items,
10},
{subscribe,
true},
{access_model,
open},
{roster_groups_allowed,
[]},
{publish_model,
publishers},
{notification_type,
headline},
{max_payload_size,
60000},
{send_last_published_item,
on_sub_and_presence},
{deliver_notifications,
true},
{presence_based_delivery,
false}],
[<<"/home">>]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:175) : pubsub init "testsite.net" [{access_createnode,
pubsub_createnode},
{ignore_pep_from_offline,
true},
{last_item_cache,
false},
{plugins,
["flat","hometree",
"pep"]}]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:258) : ** tree plugin is nodetree_tree
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:262) : ** PEP Mapping : []
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:269) : ** init flat plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:269) : ** init hometree plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:269) : ** init pep plugin
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3811) : node_call "hometree" node_to_path [<<"/home">>]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3811) : node_call "hometree" path_to_node [[]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3811) : node_call "hometree" create_node_permission ["pubsub.testsite.net",
"testsite.net",
<<"/home">>,
<<>>,
{jid,
[],
"pubsub.testsite.net",
[],
[],
"pubsub.testsite.net",
[]},
all]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3798) : tree_call "pubsub.testsite.net" create_node ["pubsub.testsite.net",
<<"/home">>,
"hometree",
{jid,
[],
"pubsub.testsite.net",
[],
[],
"pubsub.testsite.net",
[]},
[{deliver_payloads,
true},
{notify_config,
false},
{notify_delete,
false},
{notify_retract,
true},
{purge_offline,
false},
{persist_items,
true},
{max_items,
10},
{subscribe,
true},
{access_model,
open},
{roster_groups_allowed,
[]},
{publish_model,
publishers},
{notification_type,
headline},
{max_payload_size,
60000},
{send_last_published_item,
on_sub_and_presence},
{deliver_notifications,
true},
{presence_based_delivery,
false}],
[]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3811) : node_call "hometree" node_to_path [<<"/home/testsite.net">>]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3811) : node_call "hometree" path_to_node [["home"]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3811) : node_call "hometree" create_node_permission ["pubsub.testsite.net",
"testsite.net",
<<"/home/testsite.net">>,
<<"/home">>,
{jid,
[],
"pubsub.testsite.net",
[],
[],
"pubsub.testsite.net",
[]},
all]
=INFO REPORT==== 2012-08-20 22:54:31 ===
D(<0.480.0>:mod_pubsub:3798) : tree_call "pubsub.testsite.net" create_node ["pubsub.testsite.net",
<<"/home/testsite.net">>,
"hometree",
{jid,
[],
"pubsub.testsite.net",
[],
[],
"pubsub.testsite.net",
[]},
[{deliver_payloads,
true},
{notify_config,
false},
{notify_delete,
false},
{notify_retract,
true},
{purge_offline,
false},
{persist_items,
true},
{max_items,
10},
{subscribe,
true},
{access_model,
open},
{roster_groups_allowed,
[]},
{publish_model,
publishers},
{notification_type,
headline},
{max_payload_size,
60000},
{send_last_published_item,
on_sub_and_presence},
{deliver_notifications,
true},
{presence_based_delivery,
false}],
[<<"/home">>]]
=INFO REPORT==== 2012-08-20 22:54:31 ===
I(<0.533.0>:ejabberd_listener:166) : Reusing listening port for 5222
=INFO REPORT==== 2012-08-20 22:54:31 ===
I(<0.534.0>:ejabberd_listener:166) : Reusing listening port for 5269
=INFO REPORT==== 2012-08-20 22:54:31 ===
I(<0.535.0>:ejabberd_listener:166) : Reusing listening port for 5280
=INFO REPORT==== 2012-08-20 22:54:31 ===
I(<0.37.0>:ejabberd_app:72) : ejabberd 2.1.11 is started in the node ejabberd@localhost
=INFO REPORT==== 2012-08-20 22:54:52 ===
I(<0.533.0>:ejabberd_listener:281) : (#Port<0.3580>) Accepted connection {{192,168,7,10},43444} -> {{192,168,7,10},5222}
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = " <stream:stream to='node' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en' > "
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = [60,63,120,109,108,32,
118,101,114,115,105,
111,110,61,39,49,46,48,
39,63,62,60,115,116,
114,101,97,109,58,115,
116,114,101,97,109,32,
120,109,108,110,115,61,
39,106,97,98,98,101,
114,58,99,108,105,101,
110,116,39,32,120,109,
108,110,115,58,115,116,
114,101,97,109,61,39,
104,116,116,112,58,47,
47,101,116,104,101,114,
120,46,106,97,98,98,
101,114,46,111,114,103,
47,115,116,114,101,97,
109,115,39,32,105,100,
61,39,"3393693181",39,
32,102,114,111,109,61,
39,"node",39,
[" version='","1.0",
"'"],
[" xml:lang='","en",
"'"],
62]
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<stream:features><starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism></mechanisms><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='yy7di5kE0syuCXOQTXNBTclpNTo='/><register xmlns='http://jabber.org/features/iq-register'/></stream:features>">>
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = "<starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>"
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,0,1345474492877993}, Size=51
M=25.5, I=2.343
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = []
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,967.8888635846049,
1345474492904339}, Size=0
M=0.0, I=-22.814
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = []
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,483.94443179230245,
1345474492904528}, Size=0
M=0.0, I=0.685
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = []
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,241.97221589615123,
1345474492905217}, Size=0
M=0.0, I=1.447
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = " <stream:stream to='node' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en' > "
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,120.98610794807561,
1345474492906667}, Size=127
M=67.58864345665546, I=0.325
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = [60,63,120,109,108,32,
118,101,114,115,105,
111,110,61,39,49,46,48,
39,63,62,60,115,116,
114,101,97,109,58,115,
116,114,101,97,109,32,
120,109,108,110,115,61,
39,106,97,98,98,101,
114,58,99,108,105,101,
110,116,39,32,120,109,
108,110,115,58,115,116,
114,101,97,109,61,39,
104,116,116,112,58,47,
47,101,116,104,101,114,
120,46,106,97,98,98,
101,114,46,111,114,103,
47,115,116,114,101,97,
109,115,39,32,105,100,
61,39,"2534238560",39,
32,102,114,111,109,61,
39,"node",39,
[" version='","1.0",
"'"],
[" xml:lang='","en",
"'"],
62]
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<stream:features><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism></mechanisms><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='yy7di5kE0syuCXOQTXNBTclpNTo='/><register xmlns='http://jabber.org/features/iq-register'/></stream:features>">>
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = "<auth xmlns=\"urn:ietf:params:xml:ns:xmpp-sasl\" mechanism=\"PLAIN\">dGVzdGVyMSU0MHRlc3RzaXRlLm5ldEBhc2FoaQB0ZXN0ZXIxJTQwdGVzdHNpdGUubmV0AEh4MzFBOFF0RGlyZHh5M1E4VnhB</auth>"
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,0,1345474492907337}, Size=168
M=84.0, I=67.86
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.269.0>:extauth:124) : extauth call '["auth","tester1",
"node","Hx31A8QtDirdxy3Q8VxA"]' received data response:
[0,1]
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>">>
=INFO REPORT==== 2012-08-20 22:54:52 ===
I(<0.537.0>:ejabberd_c2s:631) : ({socket_state,tls,{tlssock,#Port<0.3580>,#Port<0.3608>},<0.536.0>}) Accepted authentication for tester1 by ejabberd_auth_external
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = " <stream:stream to='node' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en' > "
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,989.8190045248869,
1345474492992201}, Size=127
M=125.72004479283315, I=15.925
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = [60,63,120,109,108,32,
118,101,114,115,105,
111,110,61,39,49,46,48,
39,63,62,60,115,116,
114,101,97,109,58,115,
116,114,101,97,109,32,
120,109,108,110,115,61,
39,106,97,98,98,101,
114,58,99,108,105,101,
110,116,39,32,120,109,
108,110,115,58,115,116,
114,101,97,109,61,39,
104,116,116,112,58,47,
47,101,116,104,101,114,
120,46,106,97,98,98,
101,114,46,111,114,103,
47,115,116,114,101,97,
109,115,39,32,105,100,
61,39,"162737993",39,
32,102,114,111,109,61,
39,"node",39,
[" version='","1.0",
"'"],
[" xml:lang='","en",
"'"],
62]
=INFO REPORT==== 2012-08-20 22:54:52 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<stream:features><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'/><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='http://www.process-one.net/en/ejabberd/' ver='yy7di5kE0syuCXOQTXNBTclpNTo='/><register xmlns='http://jabber.org/features/iq-register'/></stream:features>">>
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = "<iq type=\"set\" id=\"blather0002\"><bind xmlns=\"urn:ietf:params:xml:ns:xmpp-bind\"/></iq>"
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,0,1345474493008423}, Size=85
M=42.5, I=110.706
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<iq id='blather0002' type='result'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><jid>tester1@node/28195920031345474493119328</jid></bind></iq>">>
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = "<iq type=\"set\" id=\"blather0004\" to=\"node\"><session xmlns=\"urn:ietf:params:xml:ns:xmpp-session\"/></iq>"
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,383.8892953599075,
1345474493119132}, Size=102
M=63.11448820129892, I=1.317
=INFO REPORT==== 2012-08-20 22:54:53 ===
I(<0.537.0>:ejabberd_c2s:938) : ({socket_state,tls,{tlssock,#Port<0.3580>,#Port<0.3608>},<0.536.0>}) Opened session for tester1@node/28195920031345474493119328
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<iq type='result' from='node' id='blather0004'><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/></iq>">>
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = "<iq type=\"set\" id=\"blather0006\"><query xmlns=\"jabber:iq:register\"><username>tester1</username><password>Hx31A8QtDirdxy3Q8VxA</password></query></iq>"
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,0,1345474493120895}, Size=163
M=81.5, I=62.234
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_router:313) : route
from {jid,"tester1","node",
"28195920031345474493119328","tester1",
"node","28195920031345474493119328"}
to {jid,"tester1","node",[],"tester1",
"node",[]}
packet {xmlelement,"iq",
[{"xml:lang","en"},{"type","set"},{"id","blather0006"}],
[{xmlelement,"query",
[{"xmlns","jabber:iq:register"}],
[{xmlelement,"username",[],
[{xmlcdata,<<"tester1">>}]},
{xmlelement,"password",[],
[{xmlcdata,<<"Hx31A8QtDirdxy3Q8VxA">>}]}]}]}
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_local:300) : local route
from {jid,"tester1","node",
"28195920031345474493119328","tester1",
"node","28195920031345474493119328"}
to {jid,"tester1","node",[],"tester1",
"node",[]}
packet {xmlelement,"iq",
[{"xml:lang","en"},{"type",[...]},{[...],...}],
[{xmlelement,[...],...}]}
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_sm:411) : session manager
from {jid,"tester1","node",
"28195920031345474493119328","tester1",
"node","28195920031345474493119328"}
to {jid,"tester1","node",[],"tester1",
"node",[]}
packet {xmlelement,"iq",
[{"xml:lang","en"},{"type",[...]},{[...],...}],
[{xmlelement,[...],...}]}
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.269.0>:extauth:124) : extauth call '["setpass","tester1",
"node","Hx31A8QtDirdxy3Q8VxA"]' received data response:
[0,0]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.331.0>:ejabberd_router:313) : route
from {jid,"tester1","node",[],
"tester1","node",[]}
to {jid,"tester1","node","28195920031345474493119328",
"tester1","node","28195920031345474493119328"}
packet {xmlelement,"iq",
[{"id","blather0006"},{"type","error"}],
[{xmlelement,"query",
[{"xmlns","jabber:iq:register"}],
[{xmlelement,"username",[],
[{xmlcdata,<<"tester1">>}]},
{xmlelement,"password",[],
[{xmlcdata,<<"Hx31A8QtDirdxy3Q8VxA">>}]}]},
{xmlelement,"error",
[{"code","500"},{"type","wait"}],
[{xmlelement,"internal-server-error",
[{"xmlns","urn:ietf:params:xml:ns:xmpp-stanzas"}],
[]}]}]}
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.331.0>:ejabberd_local:300) : local route
from {jid,"tester1","node",[],
"tester1","node",[]}
to {jid,"tester1","node","28195920031345474493119328",
"tester1","node","28195920031345474493119328"}
packet {xmlelement,"iq",
[{"id","blather0006"},{"type",[...]}],
[{xmlelement,[...],...},{xmlelement,...}]}
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.331.0>:ejabberd_sm:411) : session manager
from {jid,"tester1","node",[],
"tester1","node",[]}
to {jid,"tester1","node","28195920031345474493119328",
"tester1","node","28195920031345474493119328"}
packet {xmlelement,"iq",
[{"id","blather0006"},{"type",[...]}],
[{xmlelement,[...],...},{xmlelement,...}]}
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.331.0>:ejabberd_sm:510) : sending to process <0.537.0>
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = <<"<iq from='tester1@node' to='tester1@node/28195920031345474493119328' id='blather0006' type='error'><query xmlns='jabber:iq:register'><username>tester1</username><password>Hx31A8QtDirdxy3Q8VxA</password></query><error code='500' type='wait'><internal-server-error xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>">>
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:ejabberd_receiver:320) : Received XML on stream = "</stream:stream>"
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.536.0>:shaper:61) : State: {maxrate,1000,991.0260463532674,
1345474493203133}, Size=16
M=15.857693790975704, I=1.066
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:ejabberd_c2s:1553) : Send XML on stream = "</stream:stream>"
=INFO REPORT==== 2012-08-20 22:54:53 ===
I(<0.537.0>:ejabberd_c2s:1502) : ({socket_state,tls,{tlssock,#Port<0.3580>,#Port<0.3608>},<0.536.0>}) Close session for tester1@node/28195920031345474493119328
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3826) : node_action "pubsub.node" "flat" get_entity_affiliations ["pubsub.node",
{"tester1",
"node",
"28195920031345474493119328"}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_entity_affiliations ["pubsub.node",
{"tester1",
"node",
"28195920031345474493119328"}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3826) : node_action "pubsub.node" "hometree" get_entity_affiliations ["pubsub.node",
{"tester1",
"node",
"28195920031345474493119328"}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "hometree" get_entity_affiliations ["pubsub.node",
{"tester1",
"node",
"28195920031345474493119328"}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3826) : node_action "pubsub.node" "pep" get_entity_affiliations ["pubsub.node",
{"tester1",
"node",
"28195920031345474493119328"}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "pep" get_entity_affiliations ["pubsub.node",
{"tester1",
"node",
"28195920031345474493119328"}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"http://jabber.org/protocol/tune">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"1192997014">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [36,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"1332956628">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [24,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"1605112073">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [18,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"1873682400">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [19,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2000579775">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [11,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2065602784">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [37,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2083243518">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [23,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2131712298">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [21,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2159629000">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [15,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"22301278">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [38,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2240880403">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [49,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2274511791">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [34,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2368673476">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [29,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2388787692">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [25,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2607789168">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [35,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2614986158">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [52,
{jid,[],
"pubsub.node",[],
[],"pubsub.node",
[]}]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3798) : tree_call "pubsub.node" get_node ["pubsub.node",
<<"2668677210">>]
=INFO REPORT==== 2012-08-20 22:54:53 ===
D(<0.537.0>:mod_pubsub:3811) : node_call "flat" get_items [27,
{jid,[],
"pubsub.node",[], |
|
So, a couple of things:
|
|
I'm going to close this as it is effectively a duplicate of #106. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
I am using a ejabberd server with an external script for authentication. I was able to connect to it using an IM client, such as pidgin. Then a few months ago I tried to write a chatbot in ruby using the blather gem. I took the examples/echo.rb script to connect to my ejabberd server. When I had the 0.7.1 version of the blather gem, it worked fine, and I got:
Connected ! send messages to user@node
But after I upgraded blather to 0.8.0, I got an error. It would print my jid and password (no space between them) before it output the stacktrace:
Does anyone know why this is happening?
The text was updated successfully, but these errors were encountered: