search

kamax-matrix / mxisd

Federated Matrix Identity Server
GNU Affero General Public License v3.0
220 stars 112 forks source link

Can't login with 3PID?... #99

Closed jkms closed 5 years ago

jkms commented 5 years ago

I am able to successfully login using my account name, but when I try to login with my email address Riot returns: "For security, this session has been signed out. Please sign in again."

here are my MXISD logs 

Nov 29 17:53:07 MatrixHost mxisd[18419]: .738  INFO [nio-8090-exec-9]      i.k.m.c.auth.v1.AuthController : Login request with medium 'email' and address 'user@domain.com'
Nov 29 17:53:07 MatrixHost mxisd[18419]: .738  INFO [nio-8090-exec-9]   i.k.m.b.ldap.LdapThreePidProvider : Performing LDAP lookup user@domain.com of type email
Nov 29 17:53:07 MatrixHost mxisd[18419]: .760  INFO [nio-8090-exec-9]   i.k.m.b.ldap.LdapThreePidProvider : Found possible match, DN: CN=User Name,OU=Users,DC=domain,DC=com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .761  INFO [nio-8090-exec-9]   i.k.m.b.ldap.LdapThreePidProvider : DN CN=User Name,OU=Users,DC=domain,DC=com is a valid match
Nov 29 17:53:07 MatrixHost mxisd[18419]: .761  INFO [nio-8090-exec-9] l.s.RecursivePriorityLookupStrategy : Found 3PID mapping: {medium: 'email', address: 'user@domain.com', mxid: '@user:matrix.domain.com'}
Nov 29 17:53:07 MatrixHost mxisd[18419]: .761  INFO [nio-8090-exec-9]      i.k.m.c.auth.v1.AuthController : Login request with medium 'email' and address 'user@domain.com'
Nov 29 17:53:07 MatrixHost mxisd[18419]: .762  INFO [nio-8090-exec-9]   i.k.m.b.ldap.LdapThreePidProvider : Performing LDAP lookup user@domain.com of type email
Nov 29 17:53:07 MatrixHost mxisd[18419]: .773  INFO [nio-8090-exec-9]   i.k.m.b.ldap.LdapThreePidProvider : Found possible match, DN: CN=User Name,OU=Users,DC=domain,DC=com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .773  INFO [nio-8090-exec-9]   i.k.m.b.ldap.LdapThreePidProvider : DN CN=User Name,OU=Users,DC=domain,DC=com is a valid match
Nov 29 17:53:07 MatrixHost mxisd[18419]: .773  INFO [nio-8090-exec-9] l.s.RecursivePriorityLookupStrategy : Found 3PID mapping: {medium: 'email', address: 'user@domain.com', mxid: '@user:matrix.domain.com'}
Nov 29 17:53:07 MatrixHost mxisd[18419]: .774  INFO [nio-8090-exec-9]      i.k.m.c.auth.v1.AuthController : Proxy resolution: http://matrix.domain.com/_matrix/client/r0/login to http://localhost:8008/_matrix/client/r0/login
Nov 29 17:53:07 MatrixHost mxisd[18419]: .779  INFO [nio-8090-exec-2]      i.k.m.c.auth.v1.AuthController : Requested to check credentials for @user:matrix.domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .779  INFO [nio-8090-exec-2]     io.kamax.mxisd.auth.AuthManager : Attempting authentication with store LdapAuthProvider
Nov 29 17:53:07 MatrixHost mxisd[18419]: .780  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Performing auth for @user:matrix.domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .789  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Checking possible match, DN: CN=User Name,OU=Users,DC=domain,DC=com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .790  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Attempting authentication on LDAP for CN=User Name,OU=Users,DC=domain,DC=com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .796  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Authentication successful for CN=User Name,OU=Users,DC=domain,DC=com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .796  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : DN CN=User Name,OU=Users,DC=domain,DC=com is a valid match
Nov 29 17:53:07 MatrixHost mxisd[18419]: .796  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Processing 3PIDs for profile
Nov 29 17:53:07 MatrixHost mxisd[18419]: .797  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Processing 3PID type empnum
Nov 29 17:53:07 MatrixHost mxisd[18419]: .797  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : #011Attribute sAMAccountName has 1 value(s)
Nov 29 17:53:07 MatrixHost mxisd[18419]: .797  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Processing 3PID type msisdn
Nov 29 17:53:07 MatrixHost mxisd[18419]: .797  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : #011Attribute telephoneNumber has 1 value(s)
Nov 29 17:53:07 MatrixHost mxisd[18419]: .799  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : #011Attribute mobile has 1 value(s)
Nov 29 17:53:07 MatrixHost mxisd[18419]: .800  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Processing 3PID type email
Nov 29 17:53:07 MatrixHost mxisd[18419]: .800  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : #011Attribute mail has 1 value(s)
Nov 29 17:53:07 MatrixHost mxisd[18419]: .800  INFO [nio-8090-exec-2]       i.k.m.b.ldap.LdapAuthProvider : Found 4 3PIDs
Nov 29 17:53:07 MatrixHost mxisd[18419]: .800  INFO [nio-8090-exec-2]     io.kamax.mxisd.auth.AuthManager : @user:matrix.domain.com was authenticated by LdapAuthProvider, publishing 3PID mappings, if any
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]     io.kamax.mxisd.auth.AuthManager : Processing io.kamax.matrix.ThreePid@fe57fe03 for @user:matrix.domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]  i.k.m.invitation.InvitationManager : Looking up possible pending invites for msisdn:15555555555
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]     io.kamax.mxisd.auth.AuthManager : Processing io.kamax.matrix.ThreePid@58c585b0 for @user:matrix.domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]  i.k.m.invitation.InvitationManager : Looking up possible pending invites for msisdn:15555555555
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]     io.kamax.mxisd.auth.AuthManager : Processing io.kamax.matrix.ThreePid@f403d0f9 for @user:matrix.domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]  i.k.m.invitation.InvitationManager : Looking up possible pending invites for empnum:012345
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]     io.kamax.mxisd.auth.AuthManager : Processing io.kamax.matrix.ThreePid@cc7b2dd for @user:matrix.domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .801  INFO [nio-8090-exec-2]  i.k.m.invitation.InvitationManager : Looking up possible pending invites for email:user@domain.com
Nov 29 17:53:07 MatrixHost mxisd[18419]: .957  INFO [nio-8090-exec-9]      i.k.m.c.auth.v1.AuthController : http status = 200
Nov 29 17:53:10 MatrixHost mxisd[18419]: .187  INFO [nio-8090-exec-1]      i.k.m.c.auth.v1.AuthController : Proxy resolution: http://matrix.domain.com/_matrix/client/r0/login to http://localhost:8008/_matrix/client/r0/login

Corresponding syanpse auth logs:

2018-11-29 17:53:07,868 - synapse.handlers.auth - 542 - INFO - POST-15- Logging in user @user:matrix.domain.com on device DMXKZPKQPP
2018-11-29 17:53:08,757 - synapse.api.auth - 500 - WARNING - PUT-18- Unrecognised access token - not in store.
2018-11-29 17:53:08,858 - synapse.api.auth - 500 - WARNING - GET-19- Unrecognised access token - not in store.
2018-11-29 17:53:09,373 - synapse.api.auth - 500 - WARNING - POST-22- Unrecognised access token - not in store.
2018-11-29 17:53:09,530 - synapse.api.auth - 500 - WARNING - GET-23- Unrecognised access token - not in store.
2018-11-29 17:53:09,870 - synapse.api.auth - 500 - WARNING - POST-25- Unrecognised access token - not in store.

nginx:

    location /_matrix/client/r0/login {
        proxy_pass http://localhost:8090/_matrix/client/r0/login;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }

    location /_matrix/client/r0/user_directory {
        proxy_pass http://localhost:8090/_matrix/client/r0/user_directory;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }

    location /_matrix/identity {
        proxy_pass http://localhost:8090/_matrix/identity;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }

    location /_matrix {
        proxy_pass http://localhost:8008/_matrix;
        proxy_set_header Host $host;
        proxy_set_header X-Forwarded-For $remote_addr;
    }
matrix.domain: 'matrix.domain.com'
server.name: 'matrix.domain.com'
dns.overwrite.homeserver.client:
  - name: 'matrix.domain.com'
    value: 'http://localhost:8008'

# directory.exclude.homeserver: true

################
# LDAP Backend #
################
ldap.enabled: true
ldap.connection.host: 'ad.example.com'
ldap.connection.port: 389
ldap.connection.bindDn: 'CN=bind,DC=example,DC=com'
ldap.connection.bindPassword: 'password'
ldap.connection.baseDn: 'OU=Users,DC=example,DC=com'
ldap.attribute.uid.type: 'uid'
# ldap.attribute.uid.value: 'sAMAccountName'
ldap.attribute.uid.value: 'mailNickname'
ldap.attribute.name: 'cn'
ldap.attribute.threepid.email:
  - 'mail'
ldap.attribute.threepid.msisdn:
  - 'telephoneNumber'
  - 'mobile'
ldap.attribute.threepid.empnum:
  - 'sAMAccountName'

and homeserver.yaml

password_providers:
  - module: "rest_auth_provider.RestAuthProvider"
    config:
      endpoint: "http://localhost:8090"
trusted_third_party_id_servers:
    - matrix.example.com

Obviously the Unrecognised access token - not in store. is suspicious, but I don't know how to troubleshoot further.

maxidorius commented 5 years ago

Thank you for the detailed report! I don't see what could be wrong with the logs alone. I will run some regression integration tests to see if I can reproduce and will get back to you ASAP.

jkms commented 5 years ago

Thanks for the fast response @maxidor! Please let me know if I can provide any more details.

--John

maxidorius commented 5 years ago

Issue identified as trying to login with upper case characters within the username, which is not supported.