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]