ejabberd - Comments for "After upgrading ejabberd crashes"

I stopped ejabberd, then

cweiske — Fri, 30 Oct 2015 10:39:37 +0000

I stopped ejabberd, then removed the pubsub files from the file system:

$ grep 'SPOOL_DIR=/' `which ejabberdctl`
/var/lib/ejabberd
$ rm /var/lib/ejabberd/pubsub*
$ /etc/init.d/ejabber start

This made it work.

ok, so it seems you are up

mremond — Tue, 31 Mar 2015 16:42:15 +0000

ok, so it seems you are up and running, so all looks good.

Thank you - at the moment

pro007 — Mon, 30 Mar 2015 06:53:03 +0000

Thank you - at the moment crash.log is empty

To purge all PubSub data from

chris_romain — Fri, 27 Mar 2015 09:01:00 +0000

To purge all PubSub data from default backend (mnesia), you can try the following command in ejabberd debug console, then restart ejabberd. This removes everything from PubSub.

[mnesia:delete_table(T) || T<-[pubsub_last_item,pubsub_state,pubsub_item,pubsub_node,pubsub_subscription]].

That would help - thank you!

pro007 — Thu, 26 Mar 2015 07:47:53 +0000

That would help - thank you!

Do you need us to provide a

mremond — Tue, 24 Mar 2015 17:55:38 +0000

Do you need us to provide a command to clean the pubsub elements ?

default, no SQL

pro007 — Tue, 24 Mar 2015 07:50:35 +0000

default, no SQL

Yes, that clean of pep items

mremond — Wed, 18 Mar 2015 10:18:59 +0000

Yes, that clean of pep items would help. What is your pubsub backend ? Do you have special configuration to put it in SQL database or is it the default one (Mnesia) ?

Would it help to delete old

pro007 — Wed, 18 Mar 2015 07:54:21 +0000

Would it help to delete old data and to start from scratch?
How could I do this?

Reinfried

Yes, that's related to your

mremond — Tue, 17 Mar 2015 15:47:40 +0000

Yes, that's related to your crash. The issue is that you have old Pubsub data in your database from version 2.1 that ejabberd cannot understand.
That's the point of the ticket I have created on Github. Issue is now well identified. Thanks for reporting this.

Newest version of Pidgin and

pro007 — Tue, 17 Mar 2015 15:38:04 +0000

Newest version of Pidgin and Adium can authenticate, but then the client gets Verbindung zum Server verloren: Die Verbindung wurde vom Kommunikationspartner zurückgesetzt which means Lost connection to server. Connection reset by peer

I asked the users to update

pro007 — Tue, 17 Mar 2015 14:14:55 +0000

I asked the users to update psi+ and pidgin and now it looks good for most of them.
Some of them report other problems (pidgin no says "not authorized"), but I'll check this.

About PEP/pubsub:

  mod_pubsub:
    access_createnode: pubsub_createnode
    ## reduces resource comsumption, but XEP incompliant
    ignore_pep_from_offline: true
    ## XEP compliant, but increases resource comsumption
    ## ignore_pep_from_offline: false
    last_item_cache: false
    plugins:
      - "flat"
      - "hometree"
      - "pep" # pep requires mod_caps

Thanks for update. I think I

mremond — Tue, 17 Mar 2015 12:07:00 +0000

Thanks for update. I think I got an idea about what is going on.

How are your PEP / pubsub modules configured ?

For the record, we are now tracking the issue here: https://github.com/processone/ejabberd/issues/479

What I can say now: Messages

pro007 — Tue, 17 Mar 2015 10:39:02 +0000

What I can say now: Messages (OSX) works without any problems, Psi+ and Pidgin don't work:

error.log:

2015-03-17 09:56:14.868 [error] <0.17108.0> gen_fsm <0.17108.0> in state session_established terminated with reason: {badxml,{xmlel,<<"message">>,[{<<"from">>,<<"my.default@student.tugraz.at">>},{<<"to">>,<<"my.default@student.tugraz.at/Psi+">>}],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},...],...},...]},...} in xml:element_to_string/1 line 122
2015-03-17 09:56:14.870 [error] <0.17108.0> CRASH REPORT Process <0.17108.0> with 0 neighbours exited with reason: {badxml,{xmlel,<<"message">>,[{<<"from">>,<<"my.default@student.tugraz.at">>},{<<"to">>,<<"my.default@student.tugraz.at/Psi+">>}],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},...],...},...]},...} in xml:element_to_string/1 line 122 in p1_fsm:terminate/8 line 760
2015-03-17 09:56:14.871 [error] <0.359.0> Supervisor ejabberd_c2s_sup had child undefined started with {ejabberd_c2s,start_link,undefined} at <0.17108.0> exit with reason {badxml,{xmlel,<<"message">>,[{<<"from">>,<<"my.default@student.tugraz.at">>},{<<"to">>,<<"my.default@student.tugraz.at/Psi+">>}],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},...],...},...]},...} in xml:element_to_string/1 line 122 in context child_terminated

crash.log:

2015-03-17 09:56:14 =ERROR REPORT====
** State machine <0.17108.0> terminating 
** Last message in was {send_filtered,{pep_message,<<"http://jabber.org/protocol/tune+notify">>},{jid,<<"my.default">>,<<"student.tugraz.at">>,<<>>,<<"my.default">>,<<"student.tugraz.at">>,<<>>},{jid,<<"my.default">>,<<"student.tugraz.at">>,<<"Psi+">>,<<"my.default">>,<<"student.tugraz.at">>,<<"Psi+">>},{xmlel,<<"message">>,[],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"2015-02-24T13:42:33.927Z">>}],[]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"20150224T13:42:33">>}],[]}]}}
** When State == session_established
**      Data  == {state,{socket_state,p1_tls,{tlssock,#Port<0.40741>,#Port<0.41360>},<0.17107.0>},ejabberd_socket,#Ref<0.0.3.203468>,false,<<"4264472762">>,undefined,c2s,c2s_shaper,false,true,true,true,[verify_none,compression_none,{protocol_options,<<"no_tlsv1|no_sslv3">>},{certfile,<<"/etc/ssl/certs/jabber.pem">>}],true,{jid,<<"my.default">>,<<"student.tugraz.at">>,<<"Psi+">>,<<"my.default">>,<<"student.tugraz.at">>,<<"Psi+">>},<<"my.default">>,<<"student.tugraz.at">>,<<"Psi+">>,{{1426,582571,230327},<0.17108.0>},{pres_t,4},{pres_f,4},{pres_a,4},{xmlel,<<"presence">>,[{<<"xml:lang">>,<<"en">>}],[{xmlcdata,<<"\n">>},{xmlel,<<"priority">>,[],[{xmlcdata,<<"50">>}]},{xmlcdata,<<"\n">>},{xmlel,<<"c">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/caps">>},{<<"node">>,<<"http://psi-dev.googlecode.com/caps">>},{<<"ver">>,<<"0.16">>},{<<"ext">>,<<"e-time ep-notify-2 html last-act mr">>}],[]},{xmlcdata,<<"\n">>},{xmlel,<<"x">>,[{<<"xmlns">>,<<"vcard-temp:x:update">>}],[{xmlcdata,<<"\n">>},{xmlel,<<"photo">>,[],[{xmlcdata,<<"6c315463b18b830836b94c619cf8cb1b37a146b5">>}]},{xmlcdata,<<"\n">>}]},{xmlcdata,<<"\n">>}]},{1426,582574,791034},{userlist,<<"blocked">>,[{listitem,none,none,allow,100,true,false,false,false,false}],false},c2s_tls,ejabberd_auth_ldap,{{129,27,236,151},47705},[{caps_resources,{1,{{<<"my.default">>,<<"student.tugraz.at">>,<<"Psi+">>},{caps,<<"http://psi-dev.googlecode.com/caps">>,<<"0.16">>,<<>>,[<<"e-time">>,<<"ep-notify-2">>,<<"html">>,<<"last-act">>,<<"mr">>]},nil,nil}}}],active,[],inactive,undefined,undefined,500,undefined,300,false,0,0,<<"en">>}
** Reason for termination = 
** {{badxml,{xmlel,<<"message">>,[{<<"from">>,<<"my.default@student.tugraz.at">>},{<<"to">>,<<"my.default@student.tugraz.at/Psi+">>}],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"2015-02-24T13:42:33.927Z">>}],[]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"20150224T13:42:33">>}],[]}]},{function_clause,[{xml,'-crypt/1-lbc$^0/2-0-',["current",<<>>],[{file,"src/xml.erl"},{line,152}]},{xml,attr_to_list,1,[{file,"src/xml.erl"},{line,149}]},{xml,'-attrs_to_list/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,146}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,136}]},{xml,'-element_to_string_nocatch/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,137}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,137}]},{xml,'-element_to_string_nocatch/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,137}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,137}]}]}},[{xml,element_to_string,1,[{file,"src/xml.erl"},{line,122}]},{xml,element_to_binary,1,[{file,"src/xml.erl"},{line,111}]},{ejabberd_c2s,send_element,2,[{file,"src/ejabberd_c2s.erl"},{line,1912}]},{ejabberd_c2s,send_stanza,2,[{file,"src/ejabberd_c2s.erl"},{line,1927}]},{ejabberd_c2s,handle_info,3,[{file,"src/ejabberd_c2s.erl"},{line,1774}]},{p1_fsm,handle_msg,10,[{file,"src/p1_fsm.erl"},{line,582}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]}
2015-03-17 09:56:14 =CRASH REPORT====
  crasher:
    initial call: gen:init_it/6
    pid: <0.17108.0>
    registered_name: []
    exception exit: {{{badxml,{xmlel,<<"message">>,[{<<"from">>,<<"my.default@student.tugraz.at">>},{<<"to">>,<<"my.default@student.tugraz.at/Psi+">>}],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"2015-02-24T13:42:33.927Z">>}],[]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"20150224T13:42:33">>}],[]}]},{function_clause,[{xml,'-crypt/1-lbc$^0/2-0-',["current",<<>>],[{file,"src/xml.erl"},{line,152}]},{xml,attr_to_list,1,[{file,"src/xml.erl"},{line,149}]},{xml,'-attrs_to_list/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,146}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,136}]},{xml,'-element_to_string_nocatch/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,137}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,137}]},{xml,'-element_to_string_nocatch/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,137}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,137}]}]}},[{xml,element_to_string,1,[{file,"src/xml.erl"},{line,122}]},{xml,element_to_binary,1,[{file,"src/xml.erl"},{line,111}]},{ejabberd_c2s,send_element,2,[{file,"src/ejabberd_c2s.erl"},{line,1912}]},{ejabberd_c2s,send_stanza,2,[{file,"src/ejabberd_c2s.erl"},{line,1927}]},{ejabberd_c2s,handle_info,3,[{file,"src/ejabberd_c2s.erl"},{line,1774}]},{p1_fsm,handle_msg,10,[{file,"src/p1_fsm.erl"},{line,582}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},[{p1_fsm,terminate,8,[{file,"src/p1_fsm.erl"},{line,760}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]}
    ancestors: [ejabberd_c2s_sup,ejabberd_sup,<0.37.0>]
    messages: []
    links: [#Port<0.41360>,<0.359.0>]
    dictionary: [{'$internal_queue_len',0}]
    trap_exit: false
    status: running
    heap_size: 6772
    stack_size: 27
    reductions: 192293
  neighbours:
2015-03-17 09:56:14 =SUPERVISOR REPORT====
     Supervisor: {local,ejabberd_c2s_sup}
     Context:    child_terminated
     Reason:     {{badxml,{xmlel,<<"message">>,[{<<"from">>,<<"my.default@student.tugraz.at">>},{<<"to">>,<<"my.default@student.tugraz.at/Psi+">>}],[{xmlel,<<"event">>,[{<<"xmlns">>,<<"http://jabber.org/protocol/pubsub#event">>}],[{xmlel,<<"items">>,[{<<"node">>,<<"http://jabber.org/protocol/tune">>}],[{xmlel,<<"item">>,[{<<"id">>,"current"}],[{xmlcdata,<<"\n">>},{xmlelement,"tune",[{"xmlns","http://jabber.org/protocol/tune"}],[]},{xmlcdata,<<"\n">>}]}]}]},{xmlel,<<"delay">>,[{<<"xmlns">>,<<"urn:xmpp:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"2015-02-24T13:42:33.927Z">>}],[]},{xmlel,<<"x">>,[{<<"xmlns">>,<<"jabber:x:delay">>},{<<"from">>,<<"my.default@student.tugraz.at/Psi+">>},{<<"stamp">>,<<"20150224T13:42:33">>}],[]}]},{function_clause,[{xml,'-crypt/1-lbc$^0/2-0-',["current",<<>>],[{file,"src/xml.erl"},{line,152}]},{xml,attr_to_list,1,[{file,"src/xml.erl"},{line,149}]},{xml,'-attrs_to_list/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,146}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,136}]},{xml,'-element_to_string_nocatch/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,137}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,137}]},{xml,'-element_to_string_nocatch/1-lc$^0/1-0-',1,[{file,"src/xml.erl"},{line,137}]},{xml,element_to_string_nocatch,1,[{file,"src/xml.erl"},{line,137}]}]}},[{xml,element_to_string,1,[{file,"src/xml.erl"},{line,122}]},{xml,element_to_binary,1,[{file,"src/xml.erl"},{line,111}]},{ejabberd_c2s,send_element,2,[{file,"src/ejabberd_c2s.erl"},{line,1912}]},{ejabberd_c2s,send_stanza,2,[{file,"src/ejabberd_c2s.erl"},{line,1927}]},{ejabberd_c2s,handle_info,3,[{file,"src/ejabberd_c2s.erl"},{line,1774}]},{p1_fsm,handle_msg,10,[{file,"src/p1_fsm.erl"},{line,582}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]}
     Offender:   [{pid,<0.17108.0>},{name,undefined},{mfargs,{ejabberd_c2s,start_link,undefined}},{restart_type,temporary},{shutdown,1000},{child_type,worker}]

https://xmpp.net/result.php?domain=tugraz.at&type=server and https://xmpp.net/result.php?domain=tugraz.at&type=client look good.

You could post your log file

mremond — Fri, 13 Mar 2015 09:37:32 +0000

You could post your log file to a pastebin and share the link here if it is big.