matrix-org / matrix-synapse-ldap3

An LDAP3 auth provider for Synapse
Apache License 2.0
128 stars 46 forks source link

Still problems with uppercase usernames #165

Closed horstepipe closed 2 years ago

horstepipe commented 2 years ago

Hello I was happy that a PR was pushed to solve the uppercase user name problems. Unfortunately it still doesn't work here. I'm using openLDAP.

Here is a debug log output:

2022-06-12 16:18:06,070 - synapse.rest.client.login - 277 - INFO - POST-87 - Got login request with identifier: {'type': 'm.id.user', 'user': 'user'}, medium: None, address: None, user: None
2022-06-12 16:18:06,070 - ldap_auth_provider - 138 - DEBUG - POST-87 - Attempting LDAP connection with ['ldap://127.0.0.1:389']
2022-06-12 16:18:06,071 - ldap_auth_provider - 515 - DEBUG - sentinel - Established LDAP connection in simple bind mode: ldap://127.0.0.1:389 - cleartext - user: cn=readonly,ou=users,dc=xlflw,dc=top - not lazy - unbound - closed - <no socket> - tls not started - not listening - SyncStrategy - internal decoder
2022-06-12 16:18:06,074 - ldap_auth_provider - 528 - DEBUG - sentinel - LDAP Bind successful in simple bind mode.
2022-06-12 16:18:06,074 - ldap_auth_provider - 599 - DEBUG - sentinel - LDAP search filter: (&(givenName=user))
2022-06-12 16:18:06,077 - ldap_auth_provider - 620 - DEBUG - sentinel - LDAP search found dn: cn=user user@domain,cn=user,ou=groups,dc=xlflw,dc=top
2022-06-12 16:18:06,079 - ldap_auth_provider - 515 - DEBUG - sentinel - Established LDAP connection in simple bind mode: ldap://127.0.0.1:389 - cleartext - user: cn=user user@domain,cn=user,ou=groups,dc=xlflw,dc=top - not lazy - bound - open - <local: 127.0.0.1:51087 - remote: 127.0.0.1:389> - tls not started - listening - SyncStrategy - internal decoder
2022-06-12 16:18:06,081 - ldap_auth_provider - 528 - DEBUG - sentinel - LDAP Bind successful in simple bind mode.
2022-06-12 16:18:06,081 - ldap_auth_provider - 161 - DEBUG - sentinel - LDAP auth method authenticated search returned: True (conn: ldap://127.0.0.1:389 - cleartext - user: cn=user user@domain,cn=user,ou=groups,dc=xlflw,dc=top - not lazy - bound - open - <local: 127.0.0.1:51087 - remote: 127.0.0.1:389> - tls not started - listening - SyncStrategy - internal decoder)
2022-06-12 16:18:06,081 - ldap_auth_provider - 178 - INFO - sentinel - User authenticated against LDAP server: ldap://127.0.0.1:389 - cleartext - user: cn=user user@domain,cn=user,ou=groups,dc=xlflw,dc=top - not lazy - bound - open - <local: 127.0.0.1:51087 - remote: 127.0.0.1:389> - tls not started - listening - SyncStrategy - internal decoder
2022-06-12 16:18:06,082 - synapse.storage.database - 802 - WARNING - sentinel - Starting db txn 'get_users_by_id_case_insensitive' from sentinel context
2022-06-12 16:18:06,082 - synapse.storage.database - 862 - WARNING - sentinel - Starting db connection from sentinel context: metrics will be lost
2022-06-12 16:18:06,084 - synapse.storage.database - 802 - WARNING - sentinel - Starting db txn 'store_device' from sentinel context
2022-06-12 16:18:06,085 - synapse.storage.database - 862 - WARNING - sentinel - Starting db connection from sentinel context: metrics will be lost
2022-06-12 16:18:06,087 - synapse.util.metrics - 144 - WARNING - sentinel - Starting metrics collection 'notify_device_update' from sentinel context: metrics will be lost
2022-06-12 16:18:06,090 - synapse.handlers.auth - 977 - INFO - sentinel - Logging in user @user:externalsynapseurl on device VVSKWWHHCU
2022-06-12 16:18:06,091 - synapse.storage.database - 802 - WARNING - sentinel - Starting db txn 'add_access_token_to_user' from sentinel context
2022-06-12 16:18:06,091 - synapse.storage.database - 862 - WARNING - sentinel - Starting db connection from sentinel context: metrics will be lost
2022-06-12 16:18:06,093 - synapse.storage.database - 802 - WARNING - sentinel - Starting db txn 'get_device' from sentinel context
2022-06-12 16:18:06,093 - synapse.storage.database - 862 - WARNING - sentinel - Starting db connection from sentinel context: metrics will be lost
2022-06-12 16:18:06,096 - synapse.logging.context - 960 - WARNING - sentinel - Calling defer_to_threadpool from sentinel context: metrics will be lost
2022-06-12 16:18:06,097 - synapse.access.http.8008 - 450 - INFO - POST-87 - userIP2 - 8008 - {None} Processed request: 0.026sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 272B 200 "POST /_matrix/client/r0/login HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,519 - synapse.access.http.8008 - 450 - INFO - GET-89 - userIP2 - 8008 - {None} Processed request: 0.000sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 567B 200 "GET /_matrix/client/versions HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,569 - synapse.api.auth - 487 - WARNING - GET-92 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,569 - synapse.http.server - 167 - INFO - GET-92 - <XForwardedForRequest at 0x7eff10792d90 method='GET' uri='/_matrix/client/r0/thirdparty/protocols' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,570 - synapse.access.http.8008 - 450 - INFO - GET-92 - userIP2 - 8008 - {None} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.002sec/1) 88B 401 "GET /_matrix/client/r0/thirdparty/protocols HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,628 - synapse.api.auth - 487 - WARNING - GET-96 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,629 - synapse.http.server - 167 - INFO - GET-96 - <XForwardedForRequest at 0x7eff107a8850 method='GET' uri='/_matrix/client/unstable/room_keys/version' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,631 - synapse.api.auth - 487 - WARNING - POST-97 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,631 - synapse.http.server - 167 - INFO - POST-97 - <XForwardedForRequest at 0x7eff1079a430 method='POST' uri='/_matrix/client/r0/keys/upload' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,632 - synapse.access.http.8008 - 450 - INFO - GET-96 - userIP2 - 8008 - {None} Processed request: 0.001sec/0.003sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "GET /_matrix/client/unstable/room_keys/version HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,634 - synapse.access.http.8008 - 450 - INFO - POST-97 - userIP2 - 8008 - {None} Processed request: 0.001sec/0.002sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "POST /_matrix/client/r0/keys/upload HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,635 - synapse.api.auth - 487 - WARNING - GET-99 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,636 - synapse.http.server - 167 - INFO - GET-99 - <XForwardedForRequest at 0x7eff107b8ee0 method='GET' uri='/_matrix/client/r0/voip/turnServer' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,636 - synapse.access.http.8008 - 450 - INFO - GET-99 - userIP2 - 8008 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "GET /_matrix/client/r0/voip/turnServer HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,688 - synapse.api.auth - 487 - WARNING - GET-101 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,689 - synapse.http.server - 167 - INFO - GET-101 - <XForwardedForRequest at 0x7eff107a5820 method='GET' uri='/_matrix/client/r0/pushrules/' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,690 - synapse.access.http.8008 - 450 - INFO - GET-101 - userIP2 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "GET /_matrix/client/r0/pushrules/ HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,695 - synapse.api.auth - 487 - WARNING - POST-102 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,695 - synapse.http.server - 167 - INFO - POST-102 - <XForwardedForRequest at 0x7eff107984c0 method='POST' uri='/_matrix/client/r0/keys/query' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,696 - synapse.access.http.8008 - 450 - INFO - POST-102 - userIP2 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "POST /_matrix/client/r0/keys/query HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,711 - synapse.api.auth - 487 - WARNING - PUT-103 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,712 - synapse.http.server - 167 - INFO - PUT-103 - <XForwardedForRequest at 0x7eff107b58b0 method='PUT' uri='/_matrix/client/r0/presence/%40user%3Aexternalsynapseurl/status' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,713 - synapse.access.http.8008 - 450 - INFO - PUT-103 - userIP2 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "PUT /_matrix/client/r0/presence/%40user%3Aexternalsynapseurl/status HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,726 - synapse.api.auth - 487 - WARNING - POST-104 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,726 - synapse.http.server - 167 - INFO - POST-104 - <XForwardedForRequest at 0x7eff10718be0 method='POST' uri='/_matrix/client/r0/logout' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,727 - synapse.access.http.8008 - 450 - INFO - POST-104 - userIP2 - 8008 - {None} Processed request: 0.001sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "POST /_matrix/client/r0/logout HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]
2022-06-12 16:18:06,811 - synapse.api.auth - 487 - WARNING - PUT-105 - Invalid access token in auth: <class 'synapse.api.auth._InvalidMacaroonException'> .
2022-06-12 16:18:06,811 - synapse.http.server - 167 - INFO - PUT-105 - <XForwardedForRequest at 0x7eff107b57f0 method='PUT' uri='/_matrix/client/r0/presence/%40user%3Aexternalsynapseurl/status' clientproto='HTTP/1.0' site='8008'> SynapseError: 401 - Invalid access token passed.
2022-06-12 16:18:06,813 - synapse.access.http.8008 - 450 - INFO - PUT-105 - userIP2 - 8008 - {None} Processed request: 0.002sec/0.001sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 88B 401 "PUT /_matrix/client/r0/presence/%40user%3Aexternalsynapseurl/status HTTP/1.0" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:101.0) Gecko/20100101 Firefox/101.0" [0 dbevts]

Not sure whether my issue is caused by synapse itself or by that module here. But if I log in with lowercased username it works as expected.

Best regards

FrankNagel commented 2 years ago

There was no release after the PR merge, you're probably still using v0.2.0 on your Synapse server. I would love to see a new release of matrix-synapse-ldap3 used in synapse, too.

DMRobertson commented 2 years ago

I have just released https://github.com/matrix-org/matrix-synapse-ldap3/releases/tag/v0.2.1 on github and PyPI. I don't know how you've installed this module in your setup, but a pip install --upgrade matrix-synapse-ldap3 might do the trick if you've manually created a virtual env.

In the meantime I will change the Synapse repo so that v0.2.1 is included in the docker images and debian packages distributed by matrix.org. I'm not sure if this will make it in to the upcoming Synapse release (1.62, scheduled for July 5th) or the next one (1.63, July 19th).

@horstepipe I'm going to assume that the newest release of matrix-synapse-ldap3 this will fix your issue. If not, please re-open this and let us know.