warning Unexpected info: mnesia_up

[joudinet]

Environment

• ejabberd version: 21.12

• Erlang version: Erlang (SMP,ASYNC_THREADS) (BEAM) emulator version 10.7.2.14

• OS: Linux (Buildroot)

• Installed from: Buildroot

Errors from error.log/crash.log

2022-06-10 15:58:52.255985+02:00 [error] <0.708.0> ** Node '[email protected]' not responding **
** Removing (timedout) connection **

Bug description

I have a cluster of 4 ejabberd nodes. Ejabberd log is flooded by the following warning messages:

2022-06-10 15:59:01.470202+02:00 [warning] <0.1365.0>@ejabberd_s2s:handle_info/2:267 Unexpected info: {mnesia_system_event,
                     {mnesia_up,'[email protected]'}}
2022-06-10 15:59:01.473745+02:00 [warning] <0.1361.0>@ejabberd_sm_mnesia:handle_info/2:129 Unexpected info: {mnesia_system_event,
                     {mnesia_up,'[email protected]'}}

Should I worry? To be honest, I'm not sure I understand what it means. It looks to me this is simply the mnesia table from another node that inform this ejabberd node that it is up and running again. Should ejabberd handle such event and do something when it occurs?

[badlop]

Looking at the source code, the opposite mnesia_down event is handled since years ago. The most recent change in that code was in 2017: https://github.com/processone/ejabberd/commit/8639da0e00b0949b238cfbbf30845ec21976003c

The warning unexpected info was added later, in 2019, in a bulk update to bring behavior uniformity: https://github.com/processone/ejabberd/commit/6f5d99275b2c41738647dd46659ad5fd0a424827

Just looking at this, without knowing that are the exact implications, I would say it's just informative, shouldn't worry, and maybe ejabberd should handle this event and simply do nothing.

But before doing any change, all this should be checked.

[joudinet]

More on these warnings. I found out that whenever I run the following command ejabberdctl join_cluster target with success, I get four occurrences of the "Unexpected info" mnesia_up event warning message in the target's ejabberd log file. The first two warnings are the same as the one from my previous comment and these two messages are duplicated 15s later.

As you said, I guess this is just normal events when you run a join_cluster command. Ejabberd's log could probably be improved by handling such events to display a more informative entry instead of a generic warning. I think something like : [info] node XXX joined our cluster would be useful. It could also be in a debug message if you think it should not be displayed with the default loglevel.

[badlop]

Thanks for those details!

Following them, I found that the two first warnings are generated by ejabberd_s2s and ejabberd_sm_mnesia. The other two are again generated by those two modules.

I've added code to handle those cases and provide informative log messages instead of generic warnings.