-
Notifications
You must be signed in to change notification settings - Fork 89
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
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. |
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: