ejabberd
ejabberd copied to clipboard
processone
When room option "mam" set to false for mucsub room, a copy of every sent message is archived for every subscriber as a "chat" message
Environment
- ejabberd version: 22.05
- OS: Docker container
- Installed from: https://hub.docker.com/r/ejabberd/ecs
Configuration
modules:
mod_mam:
db_type: sql
default: always
request_activates_archiving: false
assume_mam_usage: true
user_mucsub_from_muc_archive: true
mod_muc:
hosts:
- "muc.@HOST@"
db_type: sql
access:
- allow
access_admin:
- allow: admin
access_create: muc_create
access_persistent: muc_create
access_mam: muc_create
history_size: 0
default_room_options:
allow_subscription: true
presence_broadcast: []
mam: true
Logs for message sent to mucsub room with "mam" option set to "true"
2022-06-24 01:43:58.160163+00:00 [debug] (#Port<0.105>) http query: 'POST' <<"/api/send_message">>
2022-06-24 01:43:58.160294+00:00 [debug] [<<"api">>,<<"send_message">>] matches [<<"api">>]
2022-06-24 01:43:58.160403+00:00 [info] API call send_message [{<<"subject">>,<<>>},
{<<"from">>,<<"[email protected]">>},
{<<"to">>,
<<"[email protected]">>},
{<<"type">>,<<"groupchat">>},
{<<"body">>,<<"hello">>}] from 100.97.226.130:33622
2022-06-24 01:43:58.160751+00:00 [debug] Command 'send_message' execution allowed by rule 'admin access' (CallerInfo=#{caller_module =>
mod_http_api,
ip =>
{100,
97,
226,
130},
tag =>
<<>>})
2022-06-24 01:43:58.160945+00:00 [debug] Executing command mod_admin_extra:send_message with Args=[<<"groupchat">>,
<<"[email protected]">>,
<<"[email protected]">>,
<<>>,<<"hello">>]
2022-06-24 01:43:58.161278+00:00 [debug] Running hook user_send_packet: mod_privacy:user_send_packet/1
2022-06-24 01:43:58.161489+00:00 [debug] Running hook user_send_packet: mod_vcard_xupdate:user_send_packet/1
2022-06-24 01:43:58.161565+00:00 [debug] Running hook user_send_packet: mod_caps:user_send_packet/1
2022-06-24 01:43:58.161620+00:00 [debug] Running hook user_send_packet: mod_mam:user_send_packet/1
2022-06-24 01:43:58.161672+00:00 [debug] Running hook user_send_packet: mod_carboncopy:user_send_packet/1
2022-06-24 01:43:58.161735+00:00 [debug] Running hook user_send_packet: mod_ping:user_send/1
2022-06-24 01:43:58.161786+00:00 [debug] Running hook user_send_packet: mod_mam:user_send_packet_strip_tag/1
2022-06-24 01:43:58.161883+00:00 [debug] Route:
#message{id = <<"5771406871740419279">>,type = groupchat,lang = <<>>,
from = #jid{user = <<"brand-3-aff-3">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"brand-3-aff-3">>,
lserver = <<"example.com">>,lresource = <<>>},
to = #jid{user = <<"5f0fe3c8bd8cee00017b24aa_12_l">>,
server = <<"muc.example.com">>,resource = <<>>,
luser = <<"5f0fe3c8bd8cee00017b24aa_12_l">>,
lserver = <<"muc.example.com">>,
lresource = <<>>},
subject = [],
body = [#text{lang = <<>>,data = <<"hello">>}],
thread = undefined,sub_els = [],meta = #{}}
2022-06-24 01:43:58.162072+00:00 [debug] Routing to MUC room <0.1025.0>:
#message{id = <<"5771406871740419279">>,type = groupchat,lang = <<>>,
from = #jid{user = <<"brand-3-aff-3">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"brand-3-aff-3">>,
lserver = <<"example.com">>,lresource = <<>>},
to = #jid{user = <<"5f0fe3c8bd8cee00017b24aa_12_l">>,
server = <<"muc.example.com">>,resource = <<>>,
luser = <<"5f0fe3c8bd8cee00017b24aa_12_l">>,
lserver = <<"muc.example.com">>,
lresource = <<>>},
subject = [],
body = [#text{lang = <<>>,data = <<"hello">>}],
thread = undefined,sub_els = [],meta = #{}}
2022-06-24 01:43:58.162416+00:00 [debug] Running hook muc_filter_message: mod_mam:muc_filter_message/3
2022-06-24 01:43:58.162539+00:00 [debug] Running hook store_mam_message: mod_push:mam_message/7
2022-06-24 01:43:58.162603+00:00 [debug] Running hook store_mam_message: mod_mam:store_mam_message/7
2022-06-24 01:43:58.162763+00:00 [debug] SQL: "INSERT INTO archive(username, timestamp, peer, bare_peer, xml, txt, kind, nick) VALUES ('[email protected]', 1656035038162528, '[email protected]', '[email protected]', '<message to=''[email protected]'' from=''[email protected]'' type=''groupchat'' id=''5771406871740419279'' xmlns=''jabber:client''><body>hello</body></message>', 'hello', 'groupchat', 'brand-3-aff-3');"
Logs for message sent to mucsub room with "mam" option set to "false"
2022-06-24 01:43:58.259128+00:00 [debug] (#Port<0.105>) http query: 'POST' <<"/api/send_message">>
2022-06-24 01:43:58.259269+00:00 [debug] [<<"api">>,<<"send_message">>] matches [<<"api">>]
2022-06-24 01:43:58.259431+00:00 [info] API call send_message [{<<"subject">>,<<"notification">>},
{<<"from">>,<<"[email protected]">>},
{<<"to">>,
<<"[email protected]">>},
{<<"type">>,<<"groupchat">>},
{<<"body">>,
<<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}] from 100.97.226.130:33622
2022-06-24 01:43:58.259721+00:00 [debug] Command 'send_message' execution allowed by rule 'admin access' (CallerInfo=#{caller_module =>
mod_http_api,
ip =>
{100,
97,
226,
130},
tag =>
<<>>})
2022-06-24 01:43:58.259850+00:00 [debug] Executing command mod_admin_extra:send_message with Args=[<<"groupchat">>,
<<"[email protected]">>,
<<"[email protected]">>,
<<"notification">>,
<<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>]
2022-06-24 01:43:58.260006+00:00 [debug] Running hook user_send_packet: mod_privacy:user_send_packet/1
2022-06-24 01:43:58.260065+00:00 [debug] Running hook user_send_packet: mod_vcard_xupdate:user_send_packet/1
2022-06-24 01:43:58.260130+00:00 [debug] Running hook user_send_packet: mod_caps:user_send_packet/1
2022-06-24 01:43:58.260170+00:00 [debug] Running hook user_send_packet: mod_mam:user_send_packet/1
2022-06-24 01:43:58.260230+00:00 [debug] Running hook user_send_packet: mod_carboncopy:user_send_packet/1
2022-06-24 01:43:58.260269+00:00 [debug] Running hook user_send_packet: mod_ping:user_send/1
2022-06-24 01:43:58.260342+00:00 [debug] Running hook user_send_packet: mod_mam:user_send_packet_strip_tag/1
2022-06-24 01:43:58.260492+00:00 [debug] Route:
#message{id = <<"10390340382896263861">>,type = groupchat,lang = <<>>,
from = #jid{user = <<"system">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
to = #jid{user = <<"notification-4">>,
server = <<"muc.example.com">>,resource = <<>>,
luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,
lresource = <<>>},
subject = [#text{lang = <<>>,data = <<"notification">>}],
body = [#text{lang = <<>>,
data = <<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}],
thread = undefined,sub_els = [],meta = #{}}
2022-06-24 01:43:58.260729+00:00 [debug] Routing to MUC room <0.784.0>:
#message{id = <<"10390340382896263861">>,type = groupchat,lang = <<>>,
from = #jid{user = <<"system">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
to = #jid{user = <<"notification-4">>,
server = <<"muc.example.com">>,resource = <<>>,
luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,
lresource = <<>>},
subject = [#text{lang = <<>>,data = <<"notification">>}],
body = [#text{lang = <<>>,
data = <<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}],
thread = undefined,sub_els = [],meta = #{}}
2022-06-24 01:43:58.305848+00:00 [debug] Running hook muc_filter_message: mod_mam:muc_filter_message/3
2022-06-24 01:43:58.306385+00:00 [debug] Route multicast:
#message{
id = <<"5178592442249249144">>,type = normal,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,server = <<"muc.example.com">>,
resource = <<>>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,lresource = <<>>},
to = undefined,subject = [],body = [],thread = undefined,
sub_els =
[#ps_event{
items =
#ps_items{
xmlns = <<>>,node = <<"urn:xmpp:mucsub:nodes:messages">>,
items =
[#ps_item{
xmlns = <<>>,id = <<"5178592442249249144">>,
sub_els =
[#message{
id = <<"10390340382896263861">>,type = groupchat,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,
server = <<"muc.example.com">>,
resource = <<"system">>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,
lresource = <<"system">>},
to = undefined,
subject = [#text{lang = <<>>,data = <<"notification">>}],
body =
[#text{
lang = <<>>,
data =
<<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}],
thread = undefined,sub_els = [],
meta =
#{muc_sender_real_jid =>
#jid{
user = <<"system">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
stanza_id => 1656035038306018}}],
node = <<>>,publisher = <<>>}],
max_items = undefined,subid = <<>>,retract = undefined},
purge = undefined,subscription = undefined,delete = undefined,
create = undefined,configuration = undefined}],
meta = #{in_muc_mam => false}}
Domain: example.com
Destinations: [email protected], [email protected]
2022-06-24 01:43:58.307088+00:00 [debug] Route:
#message{
id = <<"5178592442249249144">>,type = normal,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,server = <<"muc.example.com">>,
resource = <<>>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,lresource = <<>>},
to =
#jid{
user = <<"system">>,server = <<"example.com">>,
resource = <<>>,luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
subject = [],body = [],thread = undefined,
sub_els =
[#ps_event{
items =
#ps_items{
xmlns = <<>>,node = <<"urn:xmpp:mucsub:nodes:messages">>,
items =
[#ps_item{
xmlns = <<>>,id = <<"5178592442249249144">>,
sub_els =
[#message{
id = <<"10390340382896263861">>,type = groupchat,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,
server = <<"muc.example.com">>,
resource = <<"system">>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,
lresource = <<"system">>},
to =
#jid{
user = <<"system">>,server = <<"example.com">>,
resource = <<>>,luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
subject = [#text{lang = <<>>,data = <<"notification">>}],
body =
[#text{
lang = <<>>,
data =
<<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}],
thread = undefined,sub_els = [],
meta =
#{muc_sender_real_jid =>
#jid{
user = <<"system">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
stanza_id => 1656035038306018}}],
node = <<>>,publisher = <<>>}],
max_items = undefined,subid = <<>>,retract = undefined},
purge = undefined,subscription = undefined,delete = undefined,
create = undefined,configuration = undefined}],
meta = #{in_muc_mam => false}}
2022-06-24 01:43:58.308020+00:00 [debug] Local route:
#message{
id = <<"5178592442249249144">>,type = normal,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,server = <<"muc.example.com">>,
resource = <<>>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,lresource = <<>>},
to =
#jid{
user = <<"system">>,server = <<"example.com">>,
resource = <<>>,luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
subject = [],body = [],thread = undefined,
sub_els =
[#ps_event{
items =
#ps_items{
xmlns = <<>>,node = <<"urn:xmpp:mucsub:nodes:messages">>,
items =
[#ps_item{
xmlns = <<>>,id = <<"5178592442249249144">>,
sub_els =
[#message{
id = <<"10390340382896263861">>,type = groupchat,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,
server = <<"muc.example.com">>,
resource = <<"system">>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,
lresource = <<"system">>},
to =
#jid{
user = <<"system">>,server = <<"example.com">>,
resource = <<>>,luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
subject = [#text{lang = <<>>,data = <<"notification">>}],
body =
[#text{
lang = <<>>,
data =
<<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}],
thread = undefined,sub_els = [],
meta =
#{muc_sender_real_jid =>
#jid{
user = <<"system">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
stanza_id => 1656035038306018}}],
node = <<>>,publisher = <<>>}],
max_items = undefined,subid = <<>>,retract = undefined},
purge = undefined,subscription = undefined,delete = undefined,
create = undefined,configuration = undefined}],
meta = #{in_muc_mam => false}}
2022-06-24 01:43:58.308491+00:00 [debug] Running hook sm_receive_packet: mod_mam:sm_receive_packet/1
2022-06-24 01:43:58.308764+00:00 [debug] Processing message to bare JID:
#message{
id = <<"5178592442249249144">>,type = normal,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,server = <<"muc.example.com">>,
resource = <<>>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,lresource = <<>>},
to =
#jid{
user = <<"system">>,server = <<"example.com">>,
resource = <<>>,luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
subject = [],body = [],thread = undefined,
sub_els =
[#ps_event{
items =
#ps_items{
xmlns = <<>>,node = <<"urn:xmpp:mucsub:nodes:messages">>,
items =
[#ps_item{
xmlns = <<>>,id = <<"5178592442249249144">>,
sub_els =
[#message{
id = <<"10390340382896263861">>,type = groupchat,lang = <<>>,
from =
#jid{
user = <<"notification-4">>,
server = <<"muc.example.com">>,
resource = <<"system">>,luser = <<"notification-4">>,
lserver = <<"muc.example.com">>,
lresource = <<"system">>},
to =
#jid{
user = <<"system">>,server = <<"example.com">>,
resource = <<>>,luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
subject = [#text{lang = <<>>,data = <<"notification">>}],
body =
[#text{
lang = <<>>,
data =
<<"{\"threadId\":\"[email protected]\",\"chatUsername\":\"user-4\"}">>}],
thread = undefined,sub_els = [],
meta =
#{muc_sender_real_jid =>
#jid{
user = <<"system">>,
server = <<"example.com">>,resource = <<>>,
luser = <<"system">>,
lserver = <<"example.com">>,lresource = <<>>},
stanza_id => 1656035038306018}}],
node = <<>>,publisher = <<>>}],
max_items = undefined,subid = <<>>,retract = undefined},
purge = undefined,subscription = undefined,delete = undefined,
create = undefined,configuration = undefined}],
meta = #{in_muc_mam => false,stanza_id => 1656035038308582}}
2022-06-24 01:43:58.309336+00:00 [debug] Making request 'user_exists' for user [email protected]...
2022-06-24 01:43:58.318120+00:00 [debug] Request result: 200: <<"true">>
2022-06-24 01:43:58.318245+00:00 [debug] Running hook privacy_check_packet: mod_last:privacy_check_packet/4
2022-06-24 01:43:58.318405+00:00 [debug] Running hook privacy_check_packet: mod_privacy:check_packet/4
2022-06-24 01:43:58.318745+00:00 [debug] Running hook offline_message_hook: mod_mam:offline_message/1
2022-06-24 01:43:58.319020+00:00 [debug] Running hook store_mam_message: mod_push:mam_message/7
2022-06-24 01:43:58.319132+00:00 [debug] Running hook store_mam_message: mod_mam:store_mam_message/7
2022-06-24 01:43:58.319459+00:00 [debug] SQL: "INSERT INTO archive(username, timestamp, peer, bare_peer, xml, txt, kind, nick) VALUES ('system', 1656035038308582, '[email protected]', '[email protected]', '<message to=''[email protected]'' from=''[email protected]'' id=''5178592442249249144'' xmlns=''jabber:client''><event xmlns=''http://jabber.org/protocol/pubsub#event''><items node=''urn:xmpp:mucsub:nodes:messages''><item id=''5178592442249249144''><message to=''[email protected]'' from=''[email protected]/system'' type=''groupchat'' id=''10390340382896263861'' xmlns=''jabber:client''><body>{"threadId":"[email protected]","chatUsername":"user-4"}</body><subject>notification</subject></message></item></items></event></message>', '', 'chat', '');"
Bug description
I have two types of MUC rooms created where one type I want to archive all messages and the other I don't want to have any messages archived at all. For rooms with the "mam" option set to "true" the messages are stored in the sql database correctly with each message kind/type marked as "groupchat". However, for rooms with the "mam" option set to "false" whenever a message is sent, a copy is stored in the sql database for every room subscriber instead. e.g. muc room with 4 subscribers inserts 4 rows of the same message into the archive table of kind "chat". Not sure if this is a bug or due to a configuration that I overlooked. I've tried changing "mam" related configuration properties in my config file but no luck, still producing the same result.
I should also note that I upgraded from 18.09 to 22.05 and have followed the documented mysql upgrade guide. Each message is sent using the send_message Admin REST API endpoint. MUC rooms are created using the create_room_with_opts Admin REST API endpoint.
Can you post the mod_offline config section too?
2022-06-24 01:43:58.318745+00:00 [debug] Running hook offline_message_hook: mod_mam:offline_message/1
Can you post the
mod_offlineconfig section too?
2022-06-24 01:43:58.318745+00:00 [debug] Running hook offline_message_hook: mod_mam:offline_message/1
It's commented out so I don't think it is enabled.