Message is not archived for users having special characters in their JID

[tomhoefer]

Environment

• ejabberd version: 18.09
• Erlang version: ...
• OS: macOS Mojave
• Installed from: docker image (ejabberd/ecs:1809)

Configuration (only if needed): grep -Ev '^$|^\s*#' ejabberd.yml

###
###              ejabberd configuration file
###
### The parameters used in this configuration file are explained at
###
###       https://docs.ejabberd.im/admin/configuration
###
### The configuration file is written in YAML.
### *******************************************************
### *******           !!! WARNING !!!               *******
### *******     YAML IS INDENTATION SENSITIVE       *******
### ******* MAKE SURE YOU INDENT SECTIONS CORRECTLY *******
### *******************************************************
### Refer to http://en.wikipedia.org/wiki/YAML for the brief description.
### However, ejabberd treats different literals as different types:
###
### - unquoted or single-quoted strings. They are called "atoms".
###   Example: dog, 'Jupiter', '3.14159', YELLOW
###
### - numeric literals. Example: 3, -45.0, .0
###
### - quoted or folded strings.
###   Examples of quoted string: "Lizzard", "orange".
###   Example of folded string:
###   > Art thou not Romeo,
###     and a Montague?
###

hosts:
  - "localhost"

loglevel: 5
log_rotate_size: 10485760
log_rotate_date: ""
log_rotate_count: 1
log_rate_limit: 100

certfiles:
  - "/etc/ssl/ejabberd/key.pem"
  - "/etc/ssl/ejabberd/certificate.pem"

auth_method: http
auth_opts:
  host: "http://host.docker.internal:3000"
  connection_pool_size: 10
  connection_opts: []
  basic_auth: ""
  path_prefix: "/ejabberd/"
auth_use_cache: false
auth_password_format: plain

define_macro:
  # TLS options for client not being able to use modern ciphers (Windows XP+, Android 3.0+)
  CIPHERS_INTERMEDIATE: "ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES256-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA:!DSS"
  PROTOCOL_OPTIONS_INTERMEDIATE:
    - "no_sslv2"
    - "no_sslv3"

  # TLS options for client able to use modern ciphers (Windows 7+, Android 5.0+)
  CIPHERS_MODERN: "ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256"
  PROTOCOL_OPTIONS_MODERN:
    - "no_sslv2"
    - "no_sslv3"
    - "no_tlsv1"
    - "no_tlsv1_1"

c2s_ciphers: CIPHERS_INTERMEDIATE
c2s_protocol_options: PROTOCOL_OPTIONS_INTERMEDIATE

listen:
  -
    port: 5222
    ip: "::"
    module: ejabberd_c2s
    max_stanza_size: 262144
    shaper: c2s_shaper
    access: c2s
    starttls_required: true
  -
    port: 5269
    ip: "::"
    module: ejabberd_s2s_in
    max_stanza_size: 524288
  -
    port: 5443
    ip: "::"
    module: ejabberd_http
    request_handlers:
      "/api": mod_http_api
      "/bosh": mod_bosh
      "/upload": mod_http_upload
      "/ws": ejabberd_http_ws
    web_admin: true
    captcha: true
    ciphers: CIPHERS_INTERMEDIATE
    protocol_options: PROTOCOL_OPTIONS_INTERMEDIATE
    tls: true
  -
    port: 5280
    ip: "::"
    module: ejabberd_http
    request_handlers:
      "/api": mod_http_api
      "/bosh": mod_bosh
      "/upload": mod_http_upload
      "/ws": ejabberd_http_ws
    web_admin: true
    captcha: true

s2s_use_starttls: optional

acl:
  admin:
    user:
      - "ejabberdadmin@localhost"
  local:
    user_regexp: ""
  loopback:
    ip:
      - "127.0.0.0/8"
      - "::1/128"

access_rules:
  local:
    - allow: local
  c2s:
    - deny: blocked
    - allow
  announce:
    - allow: admin
  configure:
    - allow: admin
  muc_create:
    - allow: local
  pubsub_createnode:
    - allow: local
  register:
    - allow
  trusted_network:
    - allow: loopback

api_permissions:
  "console commands":
    from:
      - ejabberd_ctl
    who: all
    what: "*"
  "admin access":
    who:
      - access:
          - allow:
            - acl: loopback
            - acl: admin
      - oauth:
        - scope: "ejabberd:admin"
        - access:
          - allow:
            - acl: loopback
            - acl: admin
    what:
      - "*"
      - "!stop"
      - "!start"
  "public commands":
    who:
      - ip: "127.0.0.1/8"
    what:
      - "status"
      - "connected_users_number"

shaper:
  normal: 1000
  fast: 50000

shaper_rules:
  max_user_sessions: 10
  max_user_offline_messages:
    - 5000: admin
    - 100
  c2s_shaper:
    - none: admin
    - normal
  s2s_shaper: fast

modules:
  mod_adhoc: {}
  mod_admin_extra: {}
  mod_announce:
    access: announce
  mod_avatar: {}
  mod_blocking: {}
  mod_bosh: {}
  mod_caps: {}
  mod_carboncopy: {}
  mod_client_state: {}
  mod_configure: {}
  mod_disco: {}
  mod_fail2ban: {}
  mod_http_api: {}
  mod_http_upload:
    put_url: "https://@HOST@:5443/upload"
  mod_last: {}
  mod_mam:
    ## Mnesia is limited to 2GB, better to use an SQL backend
    ## For small servers SQLite is a good fit and is very easy
    ## to configure. Uncomment this when you have SQL configured:
    ## db_type: sql
    assume_mam_usage: true
    default: always
  mod_muc:
    access:
      - allow
    access_admin:
      - allow: admin
    access_create: muc_create
    access_persistent: muc_create
    default_room_options:
      mam: true
  mod_muc_admin: {}
  mod_offline:
    access_max_user_messages: max_user_offline_messages
  mod_ping: {}
  mod_privacy: {}
  mod_private: {}
  mod_proxy65:
    access: local
    max_connections: 5
  mod_pubsub:
    access_createnode: pubsub_createnode
    plugins:
      - "flat"
      - "pep"
    force_node_config:
      ## Change from "whitelist" to "open" to enable OMEMO support
      ## See https://github.com/processone/ejabberd/issues/2425
      "eu.siacs.conversations.axolotl.*":
        access_model: whitelist
      ## Avoid buggy clients to make their bookmarks public
      "storage:bookmarks":
        access_model: whitelist
  mod_push: {}
  mod_push_keepalive: {}
  mod_register:
    ## Only accept registration requests from the "trusted"
    ## network (see access_rules section above).
    ## Think twice before enabling registration from any
    ## address. See the Jabber SPAM Manifesto for details:
    ## https://github.com/ge0rg/jabber-spam-fighting-manifesto
    ip_access: trusted_network
  mod_roster:
    versioning: true
  mod_s2s_dialback: {}
  mod_shared_roster: {}
  mod_stream_mgmt:
    resend_on_timeout: if_offline
  mod_vcard: {}
  mod_vcard_xupdate: {}
  mod_version:
    show_os: false

### Local Variables:
### mode: yaml
### End:
### vim: set filetype=yaml tabstop=8

Errors from error.log/crash.log

No errors

Bug description

When sending a message from a connected user (tom-234) to an unconnected user (m-groß-gerau) the message is not archived - instead a service unavailable error is returned to the connected user:

<message xmlns='jabber:client' xml:lang='en' to='tom234@localhost/40079702737661118623235' from='m-groß-gerau@localhost' type='error' id='9902bcc1-2f8b-4f3a-9cec-79bddb825c57'>
    <error code='503' type='cancel'>
        <service-unavailable xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/>
    </error>
    <body>hi</body>
</message>

The logs show the following:

2020-09-23 18:45:14.617 [debug] <0.6524.0>@ejabberd_router:do_route:353 route:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = normal,
         lang = <<"en">>,
         from = #jid{user = <<"tom234">>,server = <<"localhost">>,
                     resource = <<"6614133440497685715858">>,
                     luser = <<"tom234">>,lserver = <<"localhost">>,
                     lresource = <<"6614133440497685715858">>},
         to = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                   server = <<"localhost">>,resource = <<>>,
                   luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                   lresource = <<>>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,sub_els = [],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},mam_archived => true}}
2020-09-23 18:45:14.618 [debug] <0.6524.0>@ejabberd_local:do_route:142 local route:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = normal,
         lang = <<"en">>,
         from = #jid{user = <<"tom234">>,server = <<"localhost">>,
                     resource = <<"6614133440497685715858">>,
                     luser = <<"tom234">>,lserver = <<"localhost">>,
                     lresource = <<"6614133440497685715858">>},
         to = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                   server = <<"localhost">>,resource = <<>>,
                   luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                   lresource = <<>>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,sub_els = [],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},mam_archived => true}}
2020-09-23 18:45:14.618 [debug] <0.6524.0>@ejabberd_sm:do_route:646 processing message to bare JID:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = normal,
         lang = <<"en">>,
         from = #jid{user = <<"tom234">>,server = <<"localhost">>,
                     resource = <<"6614133440497685715858">>,
                     luser = <<"tom234">>,lserver = <<"localhost">>,
                     lresource = <<"6614133440497685715858">>},
         to = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                   server = <<"localhost">>,resource = <<>>,
                   luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                   lresource = <<>>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,sub_els = [],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},
                  mam_archived => true,stanza_id => 1600822377337014}}
2020-09-23 18:45:14.618 [debug] <0.6524.0>@ejabberd_auth_http:make_req:224 Making request 'user_exists' for user m-gross-gerau@localhost...
2020-09-23 18:45:14.626 [debug] <0.6524.0>@ejabberd_auth_http:make_req:232 Request result: 200: <<"false">>
2020-09-23 18:45:14.627 [debug] <0.6524.0>@ejabberd_router:do_route:353 route:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = error,
         lang = <<"en">>,
         from = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                     server = <<"localhost">>,resource = <<>>,
                     luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                     lresource = <<>>},
         to = #jid{user = <<"tom234">>,server = <<"localhost">>,
                   resource = <<"6614133440497685715858">>,
                   luser = <<"tom234">>,lserver = <<"localhost">>,
                   lresource = <<"6614133440497685715858">>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,
         sub_els = [#stanza_error{type = cancel,code = 503,by = <<>>,
                                  reason = 'service-unavailable',text = [],
                                  sub_els = []}],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},
                  mam_archived => true,stanza_id => 1600822377337014}}
2020-09-23 18:45:14.628 [debug] <0.6524.0>@ejabberd_local:do_route:142 local route:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = error,
         lang = <<"en">>,
         from = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                     server = <<"localhost">>,resource = <<>>,
                     luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                     lresource = <<>>},
         to = #jid{user = <<"tom234">>,server = <<"localhost">>,
                   resource = <<"6614133440497685715858">>,
                   luser = <<"tom234">>,lserver = <<"localhost">>,
                   lresource = <<"6614133440497685715858">>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,
         sub_els = [#stanza_error{type = cancel,code = 503,by = <<>>,
                                  reason = 'service-unavailable',text = [],
                                  sub_els = []}],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},
                  mam_archived => true,stanza_id => 1600822377337014}}
2020-09-23 18:45:14.628 [debug] <0.6524.0>@ejabberd_sm:do_route:659 processing packet to full JID:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = error,
         lang = <<"en">>,
         from = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                     server = <<"localhost">>,resource = <<>>,
                     luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                     lresource = <<>>},
         to = #jid{user = <<"tom234">>,server = <<"localhost">>,
                   resource = <<"6614133440497685715858">>,
                   luser = <<"tom234">>,lserver = <<"localhost">>,
                   lresource = <<"6614133440497685715858">>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,
         sub_els = [#stanza_error{type = cancel,code = 503,by = <<>>,
                                  reason = 'service-unavailable',text = [],
                                  sub_els = []}],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},
                  mam_archived => true,stanza_id => 1600822377337014}}
2020-09-23 18:45:14.629 [debug] <0.6524.0>@ejabberd_sm:do_route:683 sending to process <0.6524.0>:
#message{id = <<"37909c1e-6d22-4a6a-96d5-d5c06246e0ba">>,type = error,
         lang = <<"en">>,
         from = #jid{user = <<109,45,103,114,111,195,159,45,103,101,114,97,117>>,
                     server = <<"localhost">>,resource = <<>>,
                     luser = <<"m-gross-gerau">>,lserver = <<"localhost">>,
                     lresource = <<>>},
         to = #jid{user = <<"tom234">>,server = <<"localhost">>,
                   resource = <<"6614133440497685715858">>,
                   luser = <<"tom234">>,lserver = <<"localhost">>,
                   lresource = <<"6614133440497685715858">>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"l">>}],
         thread = undefined,
         sub_els = [#stanza_error{type = cancel,code = 503,by = <<>>,
                                  reason = 'service-unavailable',text = [],
                                  sub_els = []}],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},
                  mam_archived => true,stanza_id => 1600822377337014}}
2020-09-23 18:45:14.629 [debug] <0.6524.0>@mod_client_state:filter_other:280 Won't add stanza for tom234@localhost/6614133440497685715858 to CSI queue
2020-09-23 18:45:14.629 [debug] <0.6524.0>@mod_client_state:dequeue_sender:331 Flushing packets of m-gross-gerau@localhost from CSI queue of tom234@localhost/6614133440497685715858

It is obvious that the http auth module cannot find the user when m-gross-gerau is sent to the auth module insteadof m-groß-gerau. This can also be reproduced if German umlauts like ä,ö or ü are part of the JID address.

When the connected user tom-234 sends a message to the unconnected user carina-darmstadt then the message gets archived as expected. In this scenario the correct user name is sent to the auth module. The 'to' user is also logged correctly instead of the byte character string (109,45,103,114,111,195,159,45,103,101,114,97,117) as it is logged for m-groß-gerau. The logs are as follows:

2020-09-23 19:08:48.897 [debug] <0.6601.0>@ejabberd_router:do_route:353 route:
#message{id = <<"d49cd085-92b4-44e9-8386-a0707450ddf9">>,type = normal,
         lang = <<"en">>,
         from = #jid{user = <<"tom234">>,server = <<"localhost">>,
                     resource = <<"40079702737661118623235">>,
                     luser = <<"tom234">>,lserver = <<"localhost">>,
                     lresource = <<"40079702737661118623235">>},
         to = #jid{user = <<"carina-darmstadt">>,server = <<"localhost">>,
                   resource = <<>>,luser = <<"carina-darmstadt">>,
                   lserver = <<"localhost">>,lresource = <<>>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"hi">>}],
         thread = undefined,sub_els = [],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},mam_archived => true}}
2020-09-23 19:08:48.898 [debug] <0.6601.0>@ejabberd_local:do_route:142 local route:
#message{id = <<"d49cd085-92b4-44e9-8386-a0707450ddf9">>,type = normal,
         lang = <<"en">>,
         from = #jid{user = <<"tom234">>,server = <<"localhost">>,
                     resource = <<"40079702737661118623235">>,
                     luser = <<"tom234">>,lserver = <<"localhost">>,
                     lresource = <<"40079702737661118623235">>},
         to = #jid{user = <<"carina-darmstadt">>,server = <<"localhost">>,
                   resource = <<>>,luser = <<"carina-darmstadt">>,
                   lserver = <<"localhost">>,lresource = <<>>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"hi">>}],
         thread = undefined,sub_els = [],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},mam_archived => true}}
2020-09-23 19:08:48.898 [debug] <0.6601.0>@ejabberd_sm:do_route:646 processing message to bare JID:
#message{id = <<"d49cd085-92b4-44e9-8386-a0707450ddf9">>,type = normal,
         lang = <<"en">>,
         from = #jid{user = <<"tom234">>,server = <<"localhost">>,
                     resource = <<"40079702737661118623235">>,
                     luser = <<"tom234">>,lserver = <<"localhost">>,
                     lresource = <<"40079702737661118623235">>},
         to = #jid{user = <<"carina-darmstadt">>,server = <<"localhost">>,
                   resource = <<>>,luser = <<"carina-darmstadt">>,
                   lserver = <<"localhost">>,lresource = <<>>},
         subject = [],
         body = [#text{lang = <<>>,data = <<"hi">>}],
         thread = undefined,sub_els = [],
         meta = #{ip => {0,0,0,0,0,65535,44049,1},
                  mam_archived => true,stanza_id => 1600823807061597}}
2020-09-23 19:08:48.898 [debug] <0.6601.0>@ejabberd_auth_http:make_req:224 Making request 'user_exists' for user carina-darmstadt@localhost...
2020-09-23 19:08:48.907 [debug] <0.6601.0>@ejabberd_auth_http:make_req:232 Request result: 200: <<"true">>

Can you pls tell me what is wrong with my setup? I hope that my explantion is understandable. If you need more information pls let me know. Thanks