Service Discovery in ejabberd 2.0.1 from Debian Lenny

My ejabberd installation is working fine, with three small glitches.

My setup in short:
- Debian Lenny (up to date)
- ejabberd 2.0.1, with custom mods: mod_asterisk and mod_shared_roster_ldap
- clients: Pidgin 2.6.5 and Psi (from 0.13 to 0.14) - various Linux distros
- all in one subnet, with local DNS server, no firewalls

Fist, service discovery seems not to be working. Tested with PSI 0.14 on ArchLinux x86.
Second, ad-hoc commands not working, they do not appear in Pidgin or I get a "not implemented" error with a return code (501 or 503, sorry I don't remember and they're not there ATM :-)
Third, searching in vcards (from LDAP) not returning any results.

I would like to address the first problem, I've been browsing the forums and Google but I haven't found any clue.
My config (edited - domain name changed) and logs (with loglevel 4, if needed I'll get more verbose logs):

ejabberd.cfg

override_global.
override_local.
override_acls.
{acl, admin, {user, "admin", "jabber.example.com"}}.
{hosts, ["jabber.example.com"]}.
{loglevel, 4}.
{listen,
 [
  {5222, ejabberd_c2s, [
			{ip, {1,2,9,144}},
			{access, c2s},
			{shaper, c2s_shaper},
			{max_stanza_size, 65536},
			starttls, {certfile, "/etc/ejabberd/ejabberd.pem"}
		       ]},
  {5269, ejabberd_s2s_in, [
			{ip, {1,2,9,144}},
			   {shaper, s2s_shaper},
			   {max_stanza_size, 131072}
			  ]},
  {5280, ejabberd_http, [
			 http_poll,
			 web_admin
			]}

 ]}.
{s2s_use_starttls, true}.
{s2s_certfile, "/etc/ejabberd/ejabberd.pem"}.
{sasl_realm, "EXAMPLE.COM"}.
{sasl_fqdn, "jabber.example.com"}.
{host_config, "jabber.example.com", [
        {auth_method, [internal]},
        {ldap_servers, ["1.2.9.9"]},
        {ldap_port, 389},
        {ldap_base, "ou=People,dc=example,dc=com"}
        ]}.
{odbc_server, {pgsql, "localhost", "ejabberd", "ejabberd", ""}}.
{shaper, normal, {maxrate, 1000}}.
{shaper, fast, {maxrate, 50000}}.
{acl, admin, {user, "superuser", "jabber.example.com"}}.
{acl, local, {user_regexp, ""}}.
{access, max_user_sessions, [{10, all}]}.
{access, local, [{allow, local}]}.
{access, c2s, [{deny, blocked},
	       {allow, all}]}.
{access, c2s_shaper, [{none, admin},
		      {normal, all}]}.
{access, s2s_shaper, [{fast, all}]}.
{access, announce, [{allow, admin}]}.
{access, configure, [{allow, admin}]}.
{access, muc_admin, [{allow, admin}]}.
{access, muc, [{allow, all}]}.
{access, register, [{deny, all}]}.
{access, pubsub_createnode, [{allow, all}]}.
{language, "pl"}.
{modules,
 [
  {mod_adhoc,    []},
  {mod_announce, [{access, announce}]}, % requires mod_adhoc
  {mod_caps,     []},
  {mod_configure,[]}, % requires mod_adhoc
  {mod_ctlextra, []},
  {mod_disco,    [
	{extra_domains, ["jabber.example.com"]},
	{server_info, [
		{all, "abuse-addresses", ["mailto:superuser@example.com"]},
		{[mod_disco], "feedback-addresses",["mailto:superuser@example.com"]},
		{[mod_disco], "admin-addresses", ["mailto:superuser@example.com"]}
	]}
  ]},
  %%{mod_echo,   [{host, "echo.localhost"}]},
  %%{mod_irc,      []},
  {mod_last_odbc,     []},
  {mod_muc,      [
		  %%{host, "conference.@HOST@"},
		  {access, muc},
		  {access_create, muc},
		  {access_persistent, muc},
		  {access_admin, muc_admin},
		  {max_users, 500}
		 ]},
  %%{mod_muc_log,[]},
  {mod_offline_odbc,  []},
  %%{mod_privacy_odbc,  []},
  %%{mod_private_odbc,  []},
  {mod_ping, []},
  {mod_proxy65,  [
		  {access, local},
		  {shaper, c2s_shaper}
		 ]},
%%  {mod_pubsub,   [
%%		  {access_createnode, pubsub_createnode},
%%		  {plugins, ["dag", "flat", "hometree", "pep"]}
%%		 ]},
  {mod_register, [
		  {welcome_message, {"Welcome!",
				     "Welcome to a Jabber service powered by Debian. "
				     "For information about Jabber visit "
				     "http://www.jabber.org"}},
		  {registration_watchers, ["superuser@jabbers.example.com"]},

		  {access, register}
		 ]},
  {mod_roster_odbc,   [{versioning, true}, {store_current_id, true}]},
  %%{mod_service_log,[]},
  %%{mod_shared_roster,[]},
  {mod_shared_roster_ldap,[
        {ldap_servers, ["1.2.9.9"]},
        {ldap_port, 389},
        {ldap_base, "ou=AddressBook,dc=example,dc=com"},
	{ldap_rfilter, "(objectClass=organizationalUnit)"},
	{ldap_gfilter, "(&(seeAlso=*)(ou=%g))"},
	{ldap_groupattr, "ou"},
	{ldap_groupdesc, "ou"},
	{ldap_memberattr, "seeAlso"},
	{ldap_memberattr_format, "uid=%u,ou=People,dc=example,dc=com"},
	{ldap_userdesc, "cn"}
  ]},
  {mod_stats,    []},
  {mod_time,     []},
  {mod_vcard,   []},
  {mod_vcard_ldap,   [
    {ldap_rootdn, ""},
    {ldap_password, ""},
    {ldap_base, "ou=AddressBook,dc=example,dc=com"},
    {ldap_uids, [{"seeAlso", "uid=%u,ou=People,dc=example,dc=com"}]},
    {ldap_filter, ""},
    {ldap_vcard_map,
	[{"NICKNAME", "%s", ["displayName"]},
	 {"FN", "%s", ["displayName"]},
	 {"LAST", "%s", ["sn"]},
	 {"FIRST", "%s", ["givenName"]},
	 {"MIDDLE", "%s", ["initials"]},
	 {"ORGNAME", "%s", ["o"]},
	 {"ORGUNIT", "%s", ["ou"]},
	 {"CTRY", "%s", ["c"]},
	 {"LOCALITY", "%s", ["l"]},
	 {"STREET", "%s", ["street"]},
	 {"REGION", "%s", ["st"]},
	 {"PCODE", "%s", ["postalCode"]},
	 {"TITLE", "%s", ["title"]},
	 {"URL", "%s", ["labeleduri"]},
	 {"DESC", "%s", ["description"]},
	 {"TEL", "%s", ["telephoneNumber"]},
	 {"EMAIL", "%s", ["mail"]},
	 {"BDAY", "%s", ["birthDay"]},
	 {"ROLE", "%s", ["employeeType"]},
	 {"PHOTO", "%s", ["jpegPhoto"]}]
    }
		]},
  {mod_version,  []},
  {mod_asterisk, [
	{cmd,"+"},
	{ami_host,"1.2.3.140"},
	{ami_port,5038},
	{ami_login,""},
	{ami_password,""}
  ]}
 ]}.

ejabberd.log


=ERROR REPORT==== 2010-01-19 13:49:36 ===
** Generic server ejabberd_local terminating 
** Last message in was {register_iq_response_handler,"jabber.example.com",
                           "2356691199",mod_caps,handle_disco_response}
** When Server state == {state}
** Reason for termination == 
** {aborted,{bad_type,{iq_response,"2356691199",mod_caps,
                                   handle_disco_response}}}

=ERROR REPORT==== 2010-01-19 13:49:36 ===
** Generic server 'ejabberd_mod_caps_jabber.example.com' terminating 
** Last message in was {'$gen_cast',
                           {note_caps,
                               {jid,"superuser","jabber.example.com","Psi",
                                   "superuser","jabber.example.com","Psi"},
                               {caps,"http://psi-im.org/caps",
                                   "0.13-dev-rev2",
                                   ["cs","ep-notify","html"]}}}
** When Server state == {state,"jabber.example.com",
                               {dict,0,16,16,8,80,48,
                                     {[],[],[],[],[],[],[],[],[],[],[],[],[],
                                      [],[],[]},
                                     {{[],[],[],[],[],[],[],[],[],[],[],[],[],
                                       [],[],[]}}},
                               []}
** Reason for termination == 
** {badarg,[{ejabberd_local,register_iq_response_handler,4},
            {mod_caps,'-handle_cast/2-fun-2-',5},
            {lists,foldl,3},
            {mod_caps,handle_cast,2},
            {gen_server,handle_msg,5},
            {proc_lib,init_p,5}]}


sasl.log

=CRASH REPORT==== 19-Jan-2010::13:53:02 ===
  crasher:
    pid: <0.507.0>
    registered_name: ejabberd_local
    exception exit: {aborted,
                        {bad_type,
                            {iq_response,"1168136996",mod_caps,
                                handle_disco_response}}}
      in function  gen_server:terminate/6
    initial call: gen:init_it(gen_server,<0.239.0>,<0.239.0>,
                              {local,ejabberd_local},
                              ejabberd_local,[],[])
    ancestors: [ejabberd_sup,<0.37.0>]
    messages: [{register_iq_response_handler,"jabber.example.com",
                      "401901379",mod_caps,handle_disco_response},
                  {register_iq_response_handler,"jabber.example.com",
                      "3198577344",mod_caps,handle_disco_response}]
    links: [<0.239.0>]
    dictionary: [{random_seed,{4090,12431,26197}}]
    trap_exit: false
    status: running
    heap_size: 1597
    stack_size: 23
    reductions: 428
  neighbours:

=PROGRESS REPORT==== 19-Jan-2010::13:53:02 ===
          supervisor: {local,ejabberd_sup}
             started: [{pid,<0.507.0>},
                       {name,ejabberd_local},
                       {mfa,{ejabberd_local,start_link,[]}},
                       {restart_type,permanent},
                       {shutdown,brutal_kill},
                       {child_type,worker}]

=SUPERVISOR REPORT==== 19-Jan-2010::13:53:02 ===
     Supervisor: {local,ejabberd_sup}
     Context:    child_terminated
     Reason:     {aborted,
                     {bad_type,
                         {iq_response,"1168136996",mod_caps,
                             handle_disco_response}}}
     Offender:   [{pid,<0.507.0>},
                  {name,ejabberd_local},
                  {mfa,{ejabberd_local,start_link,[]}},
                  {restart_type,permanent},
                  {shutdown,brutal_kill},
                  {child_type,worker}]

=PROGRESS REPORT==== 19-Jan-2010::13:53:02 ===
          supervisor: {local,ejabberd_sup}
             started: [{pid,<0.510.0>},
                       {name,ejabberd_local},
                       {mfa,{ejabberd_local,start_link,[]}},
                       {restart_type,permanent},
                       {shutdown,brutal_kill},
                       {child_type,worker}]

Quote: Fist, service

Quote:

Fist, service discovery seems not to be working. Tested with PSI 0.14 on ArchLinux x86.

You added this option to mod_disco: {extra_domains, ["jabber.example.com"]},

Remove that option, it isn't needed. And maybe it's the cause of first problem.

I was trying various

I was trying various configurations. The error in the logs from mod_caps was there before I added extra_domains.

I've removed all options from

I've removed all options from mod_caps and fixed SRV records in my local DNS server and redirected all subdomains for that host.

I think it's all about mod_caps there.

verbose logs

I've recorded some more verbose logs (loglevel 5). There are a lot of similar entries for every client that connects.

I've replaced my JID with superuser, my hostname is "jasiek".

I hope it will help to narrow down the problem:

=INFO REPORT==== 2010-01-20 09:08:55 ===
D(<0.309.0>:ejabberd_router:301) : route
        from {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        to {jid,"superuser","jabber.example.com","praca","superuser",
                "jabber.example.com","praca"}
        packet {xmlelement,"iq",
                   [{"type","get"},{"id","3049269207"}],
                   [{xmlelement,"query",
                        [{"xmlns","http://jabber.org/protocol/disco#info"},
                         {"node","http://pidgin.im/#video-v1"}],
                        []}]}

=INFO REPORT==== 2010-01-20 09:08:55 ===
D(<0.309.0>:ejabberd_s2s:250) : s2s manager
        from {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        to {jid,"superuser","jabber.example.com","praca","superuser",
                "jabber.example.com","praca"}
        packet {xmlelement,"iq",
                           [{"type","get"},{"id",[...]}],
                           [{xmlelement,[...],...}]}

=INFO REPORT==== 2010-01-20 09:08:55 ===
D(<0.309.0>:ejabberd_s2s:280) : Finding connection for {"jabber.example.com",
                                                        "jabber.example.com"}

=INFO REPORT==== 2010-01-20 09:08:55 ===
D(<0.309.0>:ejabberd_router:301) : route
        from {jid,"superuser","jabber.example.com","praca","superuser",
                  "jabber.example.com","praca"}
        to {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        packet {xmlelement,"iq",
                   [{"type","error"},{"id","3049269207"}],
                   [{xmlelement,"query",
                        [{"xmlns","http://jabber.org/protocol/disco#info"},
                         {"node","http://pidgin.im/#video-v1"}],
                        []},
                    {xmlelement,"error",
                        [{"code","503"},{"type","cancel"}],
                        [{xmlelement,"service-unavailable",
                             [{"xmlns","urn:ietf:params:xml:ns:xmpp-stanzas"}],
                             []}]}]}

=INFO REPORT==== 2010-01-20 09:08:55 ===
D(<0.309.0>:ejabberd_s2s:250) : s2s manager
        from {jid,"superuser","jabber.example.com","praca","superuser",
                  "jabber.example.com","praca"}
        to {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        packet {xmlelement,"iq",
                           [{"type","error"},{"id",[...]}],
                           [{xmlelement,[...],...},{xmlelement,...}]}

=INFO REPORT==== 2010-01-20 09:08:55 ===
D(<0.309.0>:ejabberd_s2s:280) : Finding connection for {"jabber.example.com",
                                                        "jabber.example.com"}

After some more similar caps packets:

=ERROR REPORT==== 2010-01-20 09:08:55 ===
** Generic server ejabberd_local terminating
** Last message in was {register_iq_response_handler,"jabber.nets.com.pl",
                           "3049269207",mod_caps,handle_disco_response}
** When Server state == {state}
** Reason for termination ==
** {aborted,{bad_type,{iq_response,"3049269207",mod_caps,
                                   handle_disco_response}}}

From sasl.log

=CRASH REPORT==== 20-Jan-2010::09:08:55 ===
  crasher:
    pid: <0.391.0>
    registered_name: ejabberd_local
    exception exit: {aborted,
                        {bad_type,
                            {iq_response,"3049269207",mod_caps,
                                handle_disco_response}}}
      in function  gen_server:terminate/6
    initial call: gen:init_it(gen_server,<0.239.0>,<0.239.0>,
                              {local,ejabberd_local},
                              ejabberd_local,[],[])
    ancestors: [ejabberd_sup,<0.40.0>]
    messages: [{register_iq_response_handler,"jabber.nets.com.pl",
                      "3906214387",mod_caps,handle_disco_response},
                  {register_iq_response_handler,"jabber.nets.com.pl",
                      "1166666722",mod_caps,handle_disco_response},
                  {register_iq_response_handler,"jabber.nets.com.pl",
                      "1464789244",mod_caps,handle_disco_response}]
    links: [<0.239.0>]
    dictionary: [{random_seed,{4090,17,25072}}]
    trap_exit: false
    status: running
    heap_size: 610
    stack_size: 23
    reductions: 2425
  neighbours:

=SUPERVISOR REPORT==== 20-Jan-2010::09:08:55 ===
     Supervisor: {local,ejabberd_sup}
     Context:    child_terminated
     Reason:     {aborted,
                     {bad_type,
                         {iq_response,"3049269207",mod_caps,
                             handle_disco_response}}}
     Offender:   [{pid,<0.391.0>},
                  {name,ejabberd_local},
                  {mfa,{ejabberd_local,start_link,[]}},
                  {restart_type,permanent},
                  {shutdown,brutal_kill},
                  {child_type,worker}]

After trying to browse services in Psi:

=INFO REPORT==== 2010-01-20 09:09:11 ===
D(<0.475.0>:ejabberd_router:301) : route
        from {jid,"superuser","jabber.example.com","jasiek","superuser",
                  "jabber.example.com","jasiek"}
        to {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        packet {xmlelement,"iq",
                   [{"xml:lang","pl-PL"},
                    {"type","get"},
                    {"to","jabber.example.com"},
                    {"id","aad0a"}],
                   [{xmlcdata,<<"\n">>},
                    {xmlelement,"query",
                        [{"xmlns","http://jabber.org/protocol/disco#info"}],
                        []},
                    {xmlcdata,<<"\n">>}]}

=INFO REPORT==== 2010-01-20 09:09:11 ===
D(<0.475.0>:ejabberd_local:272) : local route
        from {jid,"superuser","jabber.example.com","jasiek","superuser",
                  "jabber.example.com","jasiek"}
        to {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        packet {xmlelement,"iq",
                           [{"xml:lang","pl-PL"},
                            {"type",[...]},
                            {[...],...},
                            {...}],
                           [{xmlcdata,<<...>>},{xmlelement,...},{...}]}

=INFO REPORT==== 2010-01-20 09:09:11 ===
D(<0.475.0>:ejabberd_router:301) : route
        from {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        to {jid,"superuser","jabber.example.com","jasiek","superuser",
                "jabber.example.com","jasiek"}
        packet {xmlelement,"iq",
                   [{"type","error"},
                    {"from","jabber.example.com"},
                    {"xml:lang","pl-PL"},
                    {"id","aad0a"}],
                   [{xmlcdata,<<"\n">>},
                    {xmlelement,"query",
                        [{"xmlns","http://jabber.org/protocol/disco#info"}],
                        []},
                    {xmlcdata,<<"\n">>},
                    {xmlelement,"error",
                        [{"code","501"},{"type","cancel"}],
                        [{xmlelement,"feature-not-implemented",
                             [{"xmlns","urn:ietf:params:xml:ns:xmpp-stanzas"}],
                             []}]}]}

=INFO REPORT==== 2010-01-20 09:09:11 ===
D(<0.475.0>:ejabberd_local:272) : local route
        from {jid,[],"jabber.example.com",[],[],"jabber.example.com",[]}
        to {jid,"superuser","jabber.example.com","jasiek","superuser",
                "jabber.example.com","jasiek"}
        packet {xmlelement,"iq",
                           [{"type","error"},{"from",[...]},{[...],...},{...}],
                           [{xmlcdata,<<...>>},{xmlelement,...},{...}|...]}

I haven't found a relevant entry in sasl.log, but I guess it's ok because there were no real error, just a proper reply.

There were no errors while starting the server.

Check mod_disco is enabled

Psi gets error 501, probably because you disabled the module mod_disco. You must have mod_disco in the modules list, but without options inside. See ejabberd.cfg.example.

You should compare (using a diff tool) your config with the example one, because maybe you're keeping useless test options that break your setup.

It is enabled, with empty

It is enabled, with empty options list.

Let's suppose this is the

Let's suppose this is the very first error message, and the others are related to this one:

Quote:

ejabberd.log

=ERROR REPORT==== 2010-01-19 13:49:36 ===
** Generic server ejabberd_local terminating 
** Last message in was {register_iq_response_handler,"jabber.example.com",
                           "2356691199",mod_caps,handle_disco_response}
** When Server state == {state}
** Reason for termination == 
** {aborted,{bad_type,{iq_response,"2356691199",mod_caps,
                                   handle_disco_response}}}

When your ejabberd calls ejabberd_local:register_iq_response_handler("localhost", "2356691199",mod_caps,handle_disco_response) it finds a problem.

For my plain ejabberd 2.0.1, the call returns correctly: {register_iq_response_handler,"localhost","2356691199", mod_caps,handle_disco_response}

A simple solution may be to disable mod_caps. Probably you don't even need that module at all. It's useful mostly for XEP-0163.

XEP-0163

XEP-0163 is for pep plugin for mod_pubsub, am I right?

EDIT: you were right, after disabling mod_caps everything works as expected. Thanks for your time!

Syndicate content