search

ma1uta / ma1sd

Federated Matrix Identity Server (formerly fork of kamax/mxisd)
GNU Affero General Public License v3.0
167 stars 55 forks source link

Forward Provider not working #24

Closed ghost closed 4 years ago

ghost commented 4 years ago

Dear,

When using ma1sd together with Synapse, I enabled the forward provider in order to be able to invite people via their 3pid. It is apparently not working: when I invite someone with a matrix.org account (via the 3pid), the binding is identified correctly (mxid <> 3pid) but the invitation eventually fails (riot says that there was a failure to create the room).

See below relevant log files and config files:

ma1sd configuration:

directory:
  exclude:
    homeserver: true

dns:
  overwrite:
    homeserver:
      client:
        - name: 'matrix.nilux.be'
          value: 'http://synapse.nilux.be:8008'

enable_registration: false

forward:
  servers:
    - 'matrix-org'

hashing:
  enabled: true
  pepperLength: 20
  rotationPolicy: per_requests
  hashStorageType: sql
  algorithms:
    - sha256 
  requests: 10

key:
  path: '/var/ma1sd/secret'

ldap:
  enabled: true
  filter: '(memberOf=CN=nac-matrix,OU=access,OU=groups,dc=nilux,dc=be)'
  connection:
    host: 'slapd.nilux.be'
    tls: true
    port: 636
    bindDn: 'CN=srvmxid,OU=services,dc=nilux,dc=be'
    bindPassword: 'redact'
    baseDNs:
      - 'OU=users,dc=nilux,dc=be'
  attribute:
    name: 'cn'
    threepid:
      email:
        - 'mail'
      msisdn:
        - 'mobile'
    uid:
      type: 'uid'
      value: 'uid'

matrix:
  domain: 'matrix.nilux.be'

storage:
  provider:
    sqlite:
      database: '/var/ma1sd/db.sqlite'

threepid:
  medium:
    email:
      identity:
        from: 'redacted'
        name: 'Matrix Identity Service'
      connectors:
        smtp:
          host: 'mail.nilux.be'
          tls: 3
          port: 465

nginx config:

# HTTPS server
#
server {
    listen 443 ssl;
    listen [::]:443 ssl;
    server_name matrix.nilux.be;

    ssl_certificate         /etc/nginx/certs/live/matrix.nilux.be/fullchain.pem;
    ssl_certificate_key     /etc/nginx/certs/live/matrix.nilux.be/privkey.pem;
    ssl_trusted_certificate /etc/nginx/certs/live/matrix.nilux.be/fullchain.pem;

    ssl_session_cache shared:SSL:50m;
    ssl_session_timeout 5m;
    ssl_stapling on;
    ssl_stapling_verify on;

    ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
    ssl_ciphers   HIGH:!aNULL:!MD5:!RC4;

    ssl_dhparam /etc/nginx/dhparams.pem;
    ssl_prefer_server_ciphers on;

    set $upstream synapse.nilux.be:8008;
    add_header Strict-Transport-Security "max-age=15552000; includeSubDomains" always;
    location ~ /.well-known/matrix/ {
        default_type "text/plain";
        rewrite /.well-known/matrix/(.*) /$1 break;
        root /var/www/matrix;
    }
                      # Enable the user to authenticate with ma1sd iso the matrix HS
    # https://github.com/ma1uta/ma1sd/blob/master/docs/features/authentication.md
    location /_matrix/client/r0/login {
        proxy_pass http://ma1sd.nilux.be:8090;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }

    # also used for authentication
    location /_matrix/identity {
        proxy_pass http://ma1sd.nilux.be:8090/_matrix/identity;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }

    # user_directory allows to search users in the directory using their 3pid
    # https://github.com/ma1uta/ma1sd/blob/master/docs/features/directory.md
    location /_matrix/client/r0/user_directory {
        proxy_pass http://ma1sd.nilux.be:8090/_matrix/client/r0/user_directory;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }

    # Enable 3pid invites to work also with central matrix accounts
    # https://github.com/ma1uta/ma1sd/blob/master/docs/features/identity.md
    location ~* ^/_matrix/client/r0/rooms/([^/]+)/invite$ {
        proxy_pass  http://ma1sd.nilux.be:8090;
        proxy_set_header    Host $host;
        proxy_set_header    X-Forwarded-For $remote_addr;
    }

    location /_matrix {
        add_header Referrer-Policy "same-origin";
        fastcgi_hide_header X-Powered-By;
        proxy_set_header Host $host;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto $scheme;
        proxy_pass http://$upstream ;        
            }

    location /.well-known/acme-challenge/ {
        default_type "text/plain";
        root /var/www/letsencrypt;
    }}

ma1sd log during the invitation:

[XNIO-1 task-9] INFO io.kamax.mxisd.http.undertow.handler.identity.v1.SingleLookupHandler - Got single lookup request from ipv6_prefix:a01:aaaa:aaaa:11:1 with client Synapse/1.9.1 - Is recursive? false
[XNIO-1 task-9] INFO io.kamax.mxisd.lookup.strategy.RecursivePriorityLookupStrategy - Host ipv6_prefix:a01:aaaa:aaaa:11:1 allowed for recursion: false
[XNIO-1 task-9] INFO io.kamax.mxisd.backend.ldap.LdapThreePidProvider - Performing LDAP lookup test1040.samedi@gmail.com of type email
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 1.3.6.1.4.1.18060.0.0.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.7
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.2
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.18
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 1.2.840.113556.1.4.319
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.3
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 1.3.6.1.4.1.4203.1.10.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 1.2.840.113556.1.4.473
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.osgi.DefaultLdapCodecService - Registered pre-bundled control factory: 1.2.840.113556.1.4.474
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.18060.0.0.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.7
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.2
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.18
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.319
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.3
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.4203.1.10.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.42.2.27.8.5.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.9
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 2.16.840.1.113730.3.4.10
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.4203.1.9.1.3
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.4203.1.9.1.4
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.4203.1.9.1.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.3.6.1.4.1.4203.1.9.1.2
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.473
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.474
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.841
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.417
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.1413
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled control factory: 1.2.840.113556.1.4.528
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.1.8
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.18060.0.1.8
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.18060.0.1.3
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.18060.0.1.6
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.18060.0.1.5
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.4203.1.11.1
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.4203.1.11.3
[XNIO-1 task-9] INFO org.apache.directory.api.ldap.codec.standalone.CodecFactoryUtil - Registered pre-bundled extended operation factory: 1.3.6.1.4.1.1466.20037
[XNIO-1 task-9] INFO io.kamax.mxisd.lookup.strategy.RecursivePriorityLookupStrategy - No 3PID mapping found
[XNIO-1 task-9] INFO io.kamax.mxisd.http.undertow.handler.identity.v1.SingleLookupHandler - No mapping was found, return empty JSON object
[NioProcessor-1] WARN org.apache.directory.ldap.client.api.LdapNetworkConnection - Outbound done
javax.net.ssl.SSLException: Outbound done
    at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:528)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:641)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:48)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1114)
    at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:121)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:641)
    at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:634)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:539)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$1200(AbstractPollingIoProcessor.java:68)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1241)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1230)
    at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:683)
    at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
[XNIO-1 task-10] INFO io.kamax.mxisd.invitation.InvitationManager - Handling invite for email:test1040.samedi@gmail.com from @hntourne:matrix.nilux.be in room !LPmmmWQxxrSCAchxZu:matrix.nilux.be
[XNIO-1 task-10] INFO io.kamax.mxisd.lookup.strategy.RecursivePriorityLookupStrategy - Host Internal allowed for recursion: true
[XNIO-1 task-10] INFO io.kamax.mxisd.backend.ldap.LdapThreePidProvider - Performing LDAP lookup test1040.samedi@gmail.com of type email
[XNIO-1 task-10] INFO io.kamax.mxisd.lookup.provider.DnsLookupProvider - Performing DNS lookup for test1040.samedi@gmail.com
[XNIO-1 task-10] INFO io.kamax.mxisd.lookup.provider.DnsLookupProvider - Domain name for test1040.samedi@gmail.com: gmail.com
[XNIO-1 task-10] INFO io.kamax.mxisd.matrix.IdentityServerUtils - gmail.com is not an URL, using as-is
[XNIO-1 task-10] INFO io.kamax.mxisd.matrix.IdentityServerUtils - Discovering Identity Server for gmail.com
[XNIO-1 task-10] INFO io.kamax.mxisd.matrix.IdentityServerUtils - Performing SRV lookup
[XNIO-1 task-10] INFO io.kamax.mxisd.matrix.IdentityServerUtils - Lookup name: _matrix-identity._tcp.gmail.com
[XNIO-1 task-10] INFO io.kamax.mxisd.matrix.IdentityServerUtils - No SRV record for _matrix-identity._tcp.gmail.com
[XNIO-1 task-10] INFO io.kamax.mxisd.lookup.provider.ForwarderProvider - Using forward server https://matrix.org
[XNIO-1 task-10] INFO io.kamax.mxisd.lookup.provider.RemoteIdentityServerFetcher - Looking up email 3PID test1040.samedi@gmail.com using https://matrix.org
[XNIO-1 task-10] INFO io.kamax.mxisd.lookup.strategy.RecursivePriorityLookupStrategy - Found 3PID mapping: {medium: 'email', address: 'test1040.samedi@gmail.com', mxid: '@test2343:matrix.org'}
[XNIO-1 task-10] INFO io.kamax.mxisd.invitation.InvitationManager - Mapping for email:test1040.samedi@gmail.com already exists, refusing to store invite
[XNIO-1 task-10] INFO io.kamax.mxisd.http.undertow.handler.BasicHttpHandler - Request POST http://matrix.nilux.be/_matrix/identity/api/v1/store-invite - Error M_ALREADY_EXISTS: A mapping already exists for this 3PID
[XNIO-1 task-11] INFO io.kamax.mxisd.invitation.InvitationManager - Handling invite for email:test1040.samedi@gmail.com from @hntourne:matrix.nilux.be in room !LPmmmWQxxrSCAchxZu:matrix.nilux.be
[XNIO-1 task-11] INFO io.kamax.mxisd.lookup.strategy.RecursivePriorityLookupStrategy - Host Internal allowed for recursion: true
[XNIO-1 task-11] INFO io.kamax.mxisd.backend.ldap.LdapThreePidProvider - Performing LDAP lookup test1040.samedi@gmail.com of type email
[XNIO-1 task-11] INFO io.kamax.mxisd.lookup.provider.DnsLookupProvider - Performing DNS lookup for test1040.samedi@gmail.com
[XNIO-1 task-11] INFO io.kamax.mxisd.lookup.provider.DnsLookupProvider - Domain name for test1040.samedi@gmail.com: gmail.com
[XNIO-1 task-11] INFO io.kamax.mxisd.matrix.IdentityServerUtils - gmail.com is not an URL, using as-is
[XNIO-1 task-11] INFO io.kamax.mxisd.matrix.IdentityServerUtils - Discovering Identity Server for gmail.com
[XNIO-1 task-11] INFO io.kamax.mxisd.matrix.IdentityServerUtils - Performing SRV lookup
[XNIO-1 task-11] INFO io.kamax.mxisd.matrix.IdentityServerUtils - Lookup name: _matrix-identity._tcp.gmail.com
[XNIO-1 task-11] INFO io.kamax.mxisd.matrix.IdentityServerUtils - No SRV record for _matrix-identity._tcp.gmail.com
[XNIO-1 task-11] INFO io.kamax.mxisd.lookup.provider.ForwarderProvider - Using forward server https://matrix.org
[XNIO-1 task-11] INFO io.kamax.mxisd.lookup.provider.RemoteIdentityServerFetcher - Looking up email 3PID test1040.samedi@gmail.com using https://matrix.org
[XNIO-1 task-11] INFO io.kamax.mxisd.lookup.strategy.RecursivePriorityLookupStrategy - Found 3PID mapping: {medium: 'email', address: 'test1040.samedi@gmail.com', mxid: '@test2343:matrix.org'}
[XNIO-1 task-11] INFO io.kamax.mxisd.invitation.InvitationManager - Mapping for email:test1040.samedi@gmail.com already exists, refusing to store invite
[XNIO-1 task-11] INFO io.kamax.mxisd.http.undertow.handler.BasicHttpHandler - Request POST http://matrix.nilux.be/_matrix/identity/api/v1/store-invite - Error M_ALREADY_EXISTS: A mapping already exists for this 3PID

synapse log during the invitation:

Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,386 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22147 - ::ffff:192.168.10.67 - 8008 - Received request: OPTIONS /_matrix/client/r0/createRoom
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,389 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22147 - ::ffff:192.168.10.67 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/createRoom HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,403 - synapse.access.http.8008 - 233 - INFO - POST-22148 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: POST /_matrix/client/r0/createRoom
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,895 - synapse.access.http.8008 - 302 - INFO - GET-22146 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 11.337sec/0.001sec (0.030sec, 0.010sec) (0.027sec/0.084sec/12) 613B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63927_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,926 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22149 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: OPTIONS /_matrix/client/r0/keys/query
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,929 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22150 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63929_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,932 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22149 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {None} Processed request: 0.001sec/0.004sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/keys/query HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,934 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22150 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {None} Processed request: 0.001sec/0.003sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63929_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,941 - synapse.access.http.8008 - 233 - INFO - GET-22151 - ::ffff:192.168.10.67 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63929_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:54 server 6f4d10a4094a[784]: 2020-02-04 17:49:54,970 - synapse.access.http.8008 - 233 - INFO - POST-22152 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: POST /_matrix/client/r0/keys/query
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,005 - synapse.access.http.8008 - 302 - INFO - POST-22152 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 0.030sec/0.003sec (0.007sec, 0.000sec) (0.003sec/0.016sec/2) 971B 200 "POST /_matrix/client/r0/keys/query HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,033 - synapse.access.http.8008 - 302 - INFO - GET-22151 - ::ffff:192.168.10.67 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 0.090sec/0.001sec (0.015sec, 0.003sec) (0.006sec/0.027sec/2) 544B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63929_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,067 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22153 - ::ffff:192.168.10.67 - 8008 - Received request: OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63930_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,069 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22153 - ::ffff:192.168.10.67 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.002sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63930_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,076 - synapse.access.http.8008 - 233 - INFO - GET-22154 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63930_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,190 - synapse.access.http.8008 - 302 - INFO - GET-22154 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 0.112sec/0.002sec (0.029sec, 0.004sec) (0.008sec/0.028sec/3) 454B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63930_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,208 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22155 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63931_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,211 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22155 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63931_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,225 - synapse.access.http.8008 - 233 - INFO - GET-22156 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63931_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,360 - synapse.access.http.8008 - 302 - INFO - GET-22156 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 0.128sec/0.006sec (0.019sec, 0.000sec) (0.010sec/0.029sec/3) 461B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63931_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,372 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22157 - ::ffff:192.168.10.67 - 8008 - Received request: OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63932_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,374 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22157 - ::ffff:192.168.10.67 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63932_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,380 - synapse.access.http.8008 - 233 - INFO - GET-22158 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63932_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,659 - synapse.access.http.8008 - 302 - INFO - GET-22158 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 0.276sec/0.003sec (0.019sec, 0.005sec) (0.011sec/0.023sec/3) 456B 200 "GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63932_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,677 - synapse.access.http.8008 - 233 - INFO - OPTIONS-22159 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63933_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,679 - synapse.access.http.8008 - 302 - INFO - OPTIONS-22159 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 22B 200 "OPTIONS /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63933_2670892_506_88299_213_35_1_18345_1 HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
Feb 04 18:49:55 server 6f4d10a4094a[784]: 2020-02-04 17:49:55,686 - synapse.access.http.8008 - 233 - INFO - GET-22160 - ::ffff:192.168.10.67 - 8008 - Received request: GET /_matrix/client/r0/sync?filter=0&timeout=30000&since=s63933_2670892_506_88299_213_35_1_18345_1
Feb 04 18:49:56 server 6f4d10a4094a[784]: 2020-02-04 17:49:56,322 - synapse.access.http.8008 - 233 - INFO - GET-22161 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: GET /_matrix/federation/v1/version
Feb 04 18:49:56 server 6f4d10a4094a[784]: 2020-02-04 17:49:56,325 - synapse.access.http.8008 - 302 - INFO - GET-22161 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {None} Processed request: 0.002sec/0.001sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 51B 200 "GET /_matrix/federation/v1/version HTTP/1.0" "-" [0 dbevts]
Feb 04 18:49:57 server 6f4d10a4094a[784]: 2020-02-04 17:49:57,168 - synapse.access.http.8008 - 233 - INFO - PUT-22162 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - Received request: PUT /_matrix/federation/v1/send/1580849784
Feb 04 18:49:57 server 6f4d10a4094a[784]: 2020-02-04 17:49:57,194 - synapse.access.http.8008 - 302 - INFO - PUT-22162 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {encom.eu.org} Processed request: 0.024sec/0.001sec (0.005sec, 0.000sec) (0.002sec/0.014sec/3) 12B 200 "PUT /_matrix/federation/v1/send/1580849784 HTTP/1.0" "-" [0 dbevts]
Feb 04 18:49:57 server 6f4d10a4094a[784]: 2020-02-04 17:49:57,329 - synapse.access.http.8008 - 302 - INFO - POST-22148 - ipv6_prefix:a00:aaaa:aaaa:3:1 - 8008 - {@hntourne:matrix.nilux.be} Processed request: 2.923sec/0.002sec (0.281sec, 0.018sec) (0.083sec/0.390sec/35) 67B 500 "POST /_matrix/client/r0/createRoom HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/13.0 Safari/605.1.15 Epiphany/605.1.15" [0 dbevts]
ghost commented 4 years ago

This issue use to happen because the setup is IPv6 first. By default, ma1sd is then queried using from an IPv6 client and the recursion is denied (second line of ma1sd log above).

In this setup, I have LDAP Provider, DNS Provider and Forward Provider enabled so recursion is needed if the mxid is not found using the 3pid with the first provider (say for instance you want to lookup someone on matrix.org).

Setting the allowedCidr as per below solved the issue and now recursion works so does the Forward Provider.

lookup:
  recursive:
    enabled: true
    allowedCidr:
      - 'IPV6_SUBNET'
      - <another CIDR with mask>