search

tchapgouv / tchap-identite

Service d'Authentication pour les produits BetaGouv
https://beta.gouv.fr/startups/authentification.html
MIT License
4 stars 1 forks source link

[Preprod] Envoi OTP - Flow Bot - Erreur sur lors d'appel sur synapse /joined_members #171

Open mcalinghee opened 2 years ago

mcalinghee commented 2 years ago

Issue

In our preprod environnement, when we reserve an conf call on AudioConf, no OTP code is sent on Tchap.

Investigation

When we send the OTP code on Tchap through our Bot, we ensure that the recipient is in the room that has been created previously by calling the endpoint /joined_members. There is an internal error at this particular step.

Log client (log tchap-authentification)

2022-07-20 14:14:19.262850975 +0200 CEST [web-1] 2022-07-20 12:14:19,260 ERROR [org.beta.authentification.keycloak.authenticator.OtpLoginAuthenticator] (executor-thread-285) Sending otp via tchap bot failed for user 3e19d8875a61db10a492c5c6d04576aa8ec860db7e032e90a49d95d160026892: org.beta.authentification.matrix.exception.MatrixRuntimeException: org.beta.authentification.matrix.exception.MatrixRuntimeException: feign.FeignException$InternalServerError: [500 Internal Server Error] during [GET] to [https://matrix.i.tchap.gouv.fr/_matrix/client/unstable/rooms/%21cAlWiaTyDkuvawxlJh%3Ai.tchap.gouv.fr/joined_members] [RoomClient#getJoinedMembers(String)]: [{"errcode":"M_UNKNOWN","error":"Internal server error"}]
2022-07-20 14:14:19.263041229 +0200 CEST [web-1]    at java.base/java.lang.Thread.run(Thread.java:829)
2022-07-20 14:14:19.263247845 +0200 CEST [web-1]    ... 63 more
2022-07-20 14:14:19.263246143 +0200 CEST [web-1]    at org.beta.authentification.matrix.rest.room.RoomService.getJoinedMembers(RoomService.java:171)
2022-07-20 14:14:19.263231600 +0200 CEST [web-1]    at com.sun.proxy.$Proxy102.getJoinedMembers(Unknown Source)
2022-07-20 14:14:19.263230189 +0200 CEST [web-1]    at feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:100)
2022-07-20 14:14:19.263160476 +0200 CEST [web-1]    at feign.SynchronousMethodHandler.invoke(SynchronousMethodHandler.java:89)
2022-07-20 14:14:19.263160095 +0200 CEST [web-1]    at feign.SynchronousMethodHandler.executeAndDecode(SynchronousMethodHandler.java:138)
2022-07-20 14:14:19.263159813 +0200 CEST [web-1]    at feign.AsyncResponseHandler.handleResponse(AsyncResponseHandler.java:96)
2022-07-20 14:14:19.263159444 +0200 CEST [web-1]    at feign.codec.ErrorDecoder$Default.decode(ErrorDecoder.java:92)
2022-07-20 14:14:19.263140069 +0200 CEST [web-1]    at feign.FeignException.errorStatus(FeignException.java:185)
2022-07-20 14:14:19.263139731 +0200 CEST [web-1]    at feign.FeignException.errorStatus(FeignException.java:197)
2022-07-20 14:14:19.263139364 +0200 CEST [web-1]    at feign.FeignException.serverErrorStatus(FeignException.java:250)
2022-07-20 14:14:19.263130348 +0200 CEST [web-1] Caused by: feign.FeignException$InternalServerError: [500 Internal Server Error] during [GET] to [https://matrix.i.tchap.gouv.fr/_matrix/client/unstable/rooms/%21cAlWiaTyDkuvawxlJh%3Ai.tchap.gouv.fr/joined_members] [RoomClient#getJoinedMembers(String)]: [{"errcode":"M_UNKNOWN","error":"Internal server error"}]
2022-07-20 14:14:19.263084762 +0200 CEST [web-1]    ... 60 more
2022-07-20 14:14:19.263084030 +0200 CEST [web-1]    at org.beta.authentification.keycloak.bot.BotSender.sendMessage(BotSender.java:53)
2022-07-20 14:14:19.263061211 +0200 CEST [web-1]    at org.beta.authentification.keycloak.bot.BotSender.ensureUserIsInRoom(BotSender.java:78)
2022-07-20 14:14:19.263060562 +0200 CEST [web-1]    at org.beta.authentification.keycloak.bot.BotSender.isInvitedUserInRoom(BotSender.java:89)
2022-07-20 14:14:19.263042801 +0200 CEST [web-1]    at org.beta.authentification.matrix.rest.room.RoomService.getJoinedMembers(RoomService.java:177)
2022-07-20 14:14:19.263042064 +0200 CEST [web-1] Caused by: org.beta.authentification.matrix.exception.MatrixRuntimeException: feign.FeignException$InternalServerError: [500 Internal Server Error] during [GET] to [https://matrix.i.tchap.gouv.fr/_matrix/client/unstable/rooms/%21cAlWiaTyDkuvawxlJh%3Ai.tchap.gouv.fr/joined_members] [RoomClient#getJoinedMembers(String)]: [{"errcode":"M_UNKNOWN","error":"Internal server error"}]
2022-07-20 14:14:19.263039470 +0200 CEST [web-1]    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
2022-07-20 14:14:19.263040001 +0200 CEST [web-1]    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
2022-07-20 14:14:19.263040724 +0200 CEST [web-1]    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
mcalinghee commented 2 years ago

Un probleme qui semble similaire avait ete detecte au mois de mai par une personne sur le channel Bots et Integrations Tchap

/_matrix/client/v3/rooms/{roomId}/joined_members

mautrix.errors.request.MatrixUnknownRequestError: 502: <!DOCTYPE HTML PUBLIC "-[//IETF//DTD](https://ietf//DTD) HTML 2.0[//EN](https://en/)">
<html><head>
<title>502 Bad Gateway</title>
</head><body>
<h1>Bad Gateway</h1>
<p>The proxy server received an invalid
response from an upstream server.<br />
The proxy server could not handle the request <em><a href="/_matrix/client/r0/rooms/%21msCKkfJzzzigPMceOn%3Aagent.interieur.tchap.gouv.fr/joined_members">GET&nbsp;/_matrix/client/r0/rooms/%21msCKkfJzzzigPMceOn%3Aagent.interieur.tchap.gouv.fr/joined_members</a></em>.<p>
Reason: <strong>Error reading from remote server</strong></p></p>
</body></html>
guillaumevillemont commented 2 years ago

Related synapse logs : 

==> /mnt/logs/synapse/matrix-synapse_client_reader1.log <==
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]: 2022-07-20 14:14:19,261 - synapse.http.server - 98 - ERROR - GET-8460- Failed handle request via 'JoinedRoomMemberListRestServlet': <XForwardedForRequest at 0x7ff432c6ebe0 method='GET' uri='/_matrix/client/unstable/rooms/%21cAlWiaTyDkuvawxlJh%3Ai.tchap.gouv.fr/joined_members' clientproto='HTTP/1.1' site=15000>
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]: Traceback (most recent call last):
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:   File "/opt/synapse/env/lib/python3.7/site-packages/synapse/http/server.py", line 259, in _async_render_wrapper
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:     callback_return = await self._async_render(request)
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:   File "/opt/synapse/env/lib/python3.7/site-packages/synapse/http/server.py", line 447, in _async_render
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:     callback_return = await raw_callback_return
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:   File "/opt/synapse/env/lib/python3.7/site-packages/synapse/rest/client/v1/room.py", line 517, in on_GET
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:     requester, room_id
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:   File "/opt/synapse/env/lib/python3.7/site-packages/synapse/handlers/message.py", line 249, in get_joined_members
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]:     "Getting joined members after leaving is not implemented"
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]: NotImplementedError: Getting joined members after leaving is not implemented
Jul 20 14:14:19 tchap-i-new-2 matrix-synapse_client_reader1[38760]: 2022-07-20 14:14:19,261 - synapse.access.http.15000 - 329 - INFO - GET-8460- 171.33.105.206 - 15000 - {@tchap-identite-tchap.beta.gouv.fr:i.tchap.gouv.fr} Processed request: 0.003sec/-0.000sec (0.003sec, 0.000sec) (0.000sec/0.000sec/0) 55B 500 "GET /_matrix/client/unstable/rooms/%21cAlWiaTyDkuvawxlJh%3Ai.tchap.gouv.fr/joined_members HTTP/1.1" "okhttp/3.14.9" [0 dbevts]

Issue is already known : https://github.com/matrix-org/synapse/issues/2851 From my understanding, the error is not handled correctly (hence the stacktrace), but the behavior is expected if the bot is not in the room. The root cause might be elsewhere, though I'm gonna ask more details about the synapse issue anyway.

mcalinghee commented 2 years ago

We have cleaned (leave and forget) all the rooms and direct messages on the Bot account in preprod env. The Bot will create new room as no room exist automatically. This is now working better