"Internal error of module mod_mam has occurred during start" related to origin_id

[stevenroose]

I'm updating my ejabberd from v23.04 to v24.02 and I set the update_sql_schema: true variable, and I'm getting this error:

2024-04-24 17:50:39.083660+00:00 [info] Add column archive/origin_id:
ALTER TABLE archive ADD COLUMN
    origin_id text NOT NULL DEFAULT ('');
ALTER TABLE archive ALTER COLUMN origin_id DROP DEFAULT;

2024-04-24 17:50:39.083905+00:00 [debug] SQL: "ALTER TABLE archive ADD COLUMN
    origin_id text NOT NULL DEFAULT ('');
"
2024-04-24 17:50:39.097438+00:00 [error] SQL query 'ALTER TABLE archive ADD COLUMN
    origin_id text NOT NULL DEFAULT ('');
' failed: <<"#42S21Duplicate column name 'origin_id'">>
2024-04-24 17:50:39.097735+00:00 [error] Failed to update table archive: <<"#42S21Duplicate column name 'origin_id'">>
2024-04-24 17:50:39.108551+00:00 [critical] Internal error of module mod_mam has occurred during start:
** Options: #{default => always,cache_size => 1000,cache_missed => true,
              db_type => sql,assume_mam_usage => true,
              cache_life_time => 3600000,use_cache => true,
              clear_archive_on_room_destroy => true,access_preferences => all,
              user_mucsub_from_muc_archive => false,
              request_activates_archiving => false,compress_xml => false}
** exception error: <<"#42S21Duplicate column name 'origin_id'">>
   in function  ejabberd_sql_schema:'-do_update_schema/4-fun-5-'/4 (src/ejabberd_sql_schema.erl, line 892)
   in call from lists:foreach_1/2 (lists.erl, line 1686)
   in call from ejabberd_sql_schema:do_update_schema/4 (src/ejabberd_sql_schema.erl, line 849)
   in call from lists:foreach_1/2 (lists.erl, line 1686)
   in call from mod_mam_sql:init/2 (src/mod_mam_sql.erl, line 48)
   in call from mod_mam:start/2 (src/mod_mam.erl, line 124)
   in call from gen_mod:start_module/4 (src/gen_mod.erl, line 166)
   in call from lists:foreach_1/2 (lists.erl, line 1686)
2024-04-24 17:50:39.109119+00:00 [critical] ejabberd initialization was aborted because a module start failed.

[stevenroose]

I realized I actually don't know if I ever migrated from the "default" to the "new" schema.

I was trying to do that, using this page: https://docs.ejabberd.im/admin/configuration/database/#default-and-new-schemas

But trying to run that script on mariadb, I get this error:

ERROR 1728 (HY000) at line 5: Cannot load from mysql.proc. The table is probably corrupted

[badlop]

Maybe I didn't understand correctly, but it seems that you are doing three changes at the same time:

• upgrading ejabberd from 23.04 to 24.02
• enabling update_sql_schema, which means that ejabberd will take care to update the SQL schemas when you upgrade ejabberd
• switching from default to new schema

And you get some error message that says that a table is corrupted. What of the three changes is relevant here? No idea. What went wrong? No idea. How to solve it? No idea, of course.

I recommend you to go back to a state where your database and ejabberd servers work perfectly. And then, decide which one of the three changes you are going to perform first. Apply that change, verify that everything runs smoothly, and only then perform the second configuration change.

If something goes wrong and you cannot solve it yourself, then you can ask for help detailing one single problem that you got in one single step. There are more chances that you can get some useful help in that case.

[stevenroose]

• The upgrade from 23.04 to 24.02 without any schema changes works perfectly.
• I had new_sql_schema: true in my configuration since 2018, but tbh I don't know whether I am on the "new" or "default" schema. Is there a way to know? I might just always have ran the new schema.
• So it seems that the main issue is the update_sql_schema migration.

[badlop]

I don't know whether I am on the "new" or "default" schema. Is there a way to know? I might just always have ran the new schema.

Yes, check the schema of your SQL database, more concretely the ejabberd tables that have a username column (lke users, last, rosterusers, spool, archive... ):

• If the tables have a column server_host, then it's the "new" schema, suited for hosting many small vhosts in ejabberd.
• If the tables do not have server_host column, then it's the "default" schema, better suited for having a single vhost with many accounts.

[stevenroose]

Ok, confirmed I am already running the new schema. So it's purely the new 24.02 schema update that is failing.

[badlop]

The origin_id column in table archive was added in ejabberd 24.02 to update_sql_schema in a4bb695 to sql files in 9756819

I assume you had ejabberd 23.04 installed, MySQL database, configured like this:

new_sql_schema: true

And then you updated ejabberd to 24.02, maybe updated the SQL schema manually (or not), maybe enabled update_sql_schema before starting ejabberd (or not).

---

In any case, right now your configuration says:

new_sql_schema: true
update_sql_schema: true

For some reason, the archive table is updated to 24.02, as it contains the origin_id column. Check it with

DESCRIBE archive;

Do you have a SQL table named schema_version?

DESCRIBE schema_version;

That table should have a row for each module that ejabberd is managing its SQL table (most of them are in version 1 right now. And there should be a row with module = mod_mam_sql and version = 2

SELECT * FROM schema_version;

[stevenroose]

Thanks for the quick responses, really appreciated! I have not done any manual update, the release notes said that setting update_sql_schema: true should be sufficient. So yes, my config is exactly as you describe:

new_sql_schema: true
update_sql_schema: true

After starting like this, ejabberd would not be able to start, resulting in the error given above. I proceeded to remove the update line and restart again which is running successfully now.

DESCRIBE archive;

Field   Type    Null    Key     Default Extra
username        varchar(191)    NO              NULL
server_host     text    NO      MUL     NULL
timestamp       bigint(20) unsigned     NO              NULL
peer    varchar(191)    NO              NULL
bare_peer       varchar(191)    NO              NULL
xml     text    NO              NULL
txt     text    YES     MUL     NULL
id      bigint(20) unsigned     NO      PRI     NULL    auto_increment
kind    varchar(10)     YES             NULL
nick    varchar(191)    YES             NULL
created_at      timestamp       NO              current_timestamp()
origin_id       text    NO              ''

DESCRIBE schema_version;

Field   Type    Null    Key     Default Extra
module  text    NO      UNI     NULL
version bigint(20)      NO              NULL

SELECT * FROM schema_version;

module  version
mod_mam_sql     1

[badlop]

i can reproduce your error message this way:

1. setup sql database
2. configure sql in ejabberd, also enable update_sql_schema
3. start ejabberd, it will create tables and fill the table schema_version
4. modify schema_version: change mod_mam_sql from 2 to 1
5. restart ejabberd, it will attempt to update archive table, but of course it's already updated

no idea why you got to that state. solution: revert step 4.

[stevenroose]

Hmm, ok setting the version manually in schema_version worked. Strange. I only have one record in that table as well.