Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

/messages returns the 4XX status code and error of a remote homeserver when backfilling, which is confusing #3736

Open
krombel opened this issue Aug 22, 2018 · 3 comments
Labels
A-Messages-Endpoint /messages client API endpoint (`RoomMessageListRestServlet`) (which also triggers /backfill) O-Occasional Affects or can be seen by some users regularly or most users rarely S-Minor Blocks non-critical functionality, workarounds exist. T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues.

Comments

@krombel
Copy link
Contributor

krombel commented Aug 22, 2018

Description

/messages returns 500 Internal Server Error when backfilling #matrix-dev:matrix.org from a server which has removed that room from their database

Steps to reproduce

  • Try backfilling #matrix-dev:matrix.org

Version information

  • Homeserver: another homeserver
  • Version: 0.33.2

Logs

2018-08-22 13:25:17,093 - synapse.handlers.federation - 790 - ERROR - GET-66416 - Failed to backfill from chat.weho.st because FirstError[#0, [Failure instance: Traceback: <class 'synapse.api.errors.SynapseError'>: 403: Room '!XqBunHwQIXUiqCaoxq:matrix.org' does not exist
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1418:_inlineCallbacks
synapse/handlers/federation.py:1607:_prep_event
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1613:unwindGenerator
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1529:_cancellableInlineCallbacks
--- <exception caught here> ---
synapse/handlers/federation.py:1607:_prep_event
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1418:_inlineCallbacks
synapse/handlers/federation.py:1903:do_auth
synapse/api/auth.py:90:check
synapse/event_auth.py:95:check
]]
Traceback (most recent call last):
  File "synapse/handlers/federation.py", line 760, in try_backfill
    extremities=extremities,
FirstError: FirstError[#0, [Failure instance: Traceback: <class 'synapse.api.errors.SynapseError'>: 403: Room '!XqBunHwQIXUiqCaoxq:matrix.org' does not exist
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1418:_inlineCallbacks
synapse/handlers/federation.py:1607:_prep_event
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1613:unwindGenerator
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1529:_cancellableInlineCallbacks
--- <exception caught here> ---
synapse/handlers/federation.py:1607:_prep_event
/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py:1418:_inlineCallbacks
synapse/handlers/federation.py:1903:do_auth
synapse/api/auth.py:90:check
synapse/event_auth.py:95:check
]]
2018-08-22 13:25:17,096 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server catalk.xyz.
2018-08-22 13:25:17,100 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server klen.site.
2018-08-22 13:25:17,101 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server onat.edu.ua.
2018-08-22 13:25:17,103 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server moulticast.net.
2018-08-22 13:25:17,112 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server dawninglight.net.
2018-08-22 13:25:17,114 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server yannikenss.de.
2018-08-22 13:25:17,116 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server aerens.be.
2018-08-22 13:25:17,118 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server lvps.eu.
2018-08-22 13:25:17,119 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server matrix.cigliola.com.
2018-08-22 13:25:17,120 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server veeedo.com.
2018-08-22 13:25:17,121 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server pawelmandera.com.
2018-08-22 13:25:17,123 - synapse.handlers.federation - 782 - INFO - GET-66416 - Not retrying server home.shrike.me.
2018-08-22 13:25:17,123 - synapse.http.outbound - 164 - INFO - GET-66416 - {GET-O-77660} [fiksel.info] Sending request: GET matrix://fiksel.info/_matrix/federation/v1/backfill/%21XqBunHwQIXUiqCaoxq%3Amatrix.org/?limit=100&v=%241416421050073wSUwI%3Amatrix.org&v=%241416420914590avyez%3Ajki.re&v=%241416420914880oFczF%3Ajki.re&v=%241416421009533vfDhR%3Amatrix.org&v=%241416420916528LUXWH%3Amatrix.org
2018-08-22 13:25:17,125 - synapse.http.endpoint - 332 - INFO - GET-66416 - Connecting to matrix.fiksel.info:8448
2018-08-22 13:25:17,293 - synapse.http.outbound - 246 - INFO - GET-66416 - {GET-O-77660} [fiksel.info] Result: 403 Forbidden
2018-08-22 13:25:17,296 - synapse.http.server - 98 - ERROR - GET-66416 - Failed handle request via <function _async_render at 0x7f84b8855ed8>: <XForwardedForRequest at 0x7f84575264d0 method='GET' uri='/_matrix/client/r0/rooms/!XqBunHwQIXUiqCaoxq%3Amatrix.org/messages?from=s600799_25561883_851_986906_54160_68_13448_75210_14&limit=20&dir=b' clientproto='HTTP/1.1' site=8008>: Traceback (most recent call last):
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
--- <exception caught here> ---
  File "synapse/http/server.py", line 78, in wrapped_request_handler
    yield h(self, request)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/http/server.py", line 313, in _async_render
    callback_return = yield callback(request, **kwargs)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/rest/client/v1/room.py", line 450, in on_GET
    event_filter=event_filter,
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/handlers/pagination.py", line 221, in get_messages
    room_id, max_topo
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/handlers/federation.py", line 796, in maybe_backfill
    success = yield try_backfill(likely_domains)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/handlers/federation.py", line 760, in try_backfill
    extremities=extremities,
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/handlers/federation.py", line 518, in backfill
    extremities=extremities,
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/federation/federation_client.py", line 189, in backfill
    dest, context, extremities, limit)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "synapse/http/matrixfederationclient.py", line 486, in get_json
    ignore_backoff=ignore_backoff,
  File "/srv/synapse/env/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "synapse/http/matrixfederationclient.py", line 257, in _request
    response.code, response.phrase, body
synapse.api.errors.HttpResponseException: 403: Forbidden
2018-08-22 13:25:17,297 - synapse.access.http.8008 - 139 - INFO - GET-66416 - 212.204.110.133 - 8008 - {@me:myserver.net} Processed request: 9.264sec (1.064sec, 0.280sec) (0.257sec/1.272sec/90) 55B 500 "GET /_matrix/client/r0/rooms/!XqBunHwQIXUiqCaoxq%3Amatrix.org/messages?from=s600799_25561883_851_986906_54160_68_13448_75210_14&limit=20&dir=b HTTP/1.1" "<UserAgent>" [43 dbevts]
@krombel krombel changed the title /messages returns 500 when back-filling from server which has removed the room from their server /messages returns 500 when trying to backfill from server which has removed the room from their server Aug 22, 2018
@neilisfragile neilisfragile added z-p2 (Deprecated Label) z-minor (Deprecated Label) labels Oct 5, 2018
@richvdh richvdh changed the title /messages returns 500 when trying to backfill from server which has removed the room from their server /messages returns 500 when trying to backfill from server which returns a 403 Feb 6, 2020
@richvdh richvdh added the z-bug (Deprecated Label) label Feb 6, 2020
@richvdh
Copy link
Member

richvdh commented Feb 6, 2020

As another datapoint: attempts to backfill !PcCidzjUKXHKImhTrB:matrix.org (#mozilla_#rust:matrix.org) on matrix.org are currently failing with a 500, because matrix.org has decided to try to backfill from vanpetegem.me, which is responding with {"errcode": "M_FORBIDDEN", "error": "Host not in room."}.

@tanriol
Copy link

tanriol commented Feb 7, 2020

I don't have a good understanding of backfill... is this a possible DoS vector by which a malicious server could effectively disable a public room and require admin intervention to fix?

@MadLittleMods MadLittleMods added the T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues. label Apr 21, 2022
@anoadragon453
Copy link
Member

anoadragon453 commented Apr 28, 2022

Since #7556, if you receive a 4XX from the remote server, the client will be passed the same status code (i.e. 403) - no longer always a 500.

try:
await self._federation_event_handler.backfill(
dom, room_id, limit=100, extremities=extremities_to_request
)
# If this succeeded then we probably already have the
# appropriate stuff.
# TODO: We can probably do something more intelligent here.
return True
except (SynapseError, InvalidResponseError) as e:
logger.info("Failed to backfill from %s because %s", dom, e)
continue
except HttpResponseException as e:
if 400 <= e.code < 500:
raise e.to_synapse_error()
logger.info("Failed to backfill from %s because %s", dom, e)
continue

@anoadragon453 anoadragon453 changed the title /messages returns 500 when trying to backfill from server which returns a 403 /messages returns the 4XX status code and error of a remote homeserver when backfilling, which is confusing Apr 28, 2022
@MadLittleMods MadLittleMods added the A-Messages-Endpoint /messages client API endpoint (`RoomMessageListRestServlet`) (which also triggers /backfill) label Jul 19, 2022
@squahtx squahtx added S-Minor Blocks non-critical functionality, workarounds exist. O-Occasional Affects or can be seen by some users regularly or most users rarely and removed z-bug (Deprecated Label) z-p2 (Deprecated Label) z-minor (Deprecated Label) labels Oct 5, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
A-Messages-Endpoint /messages client API endpoint (`RoomMessageListRestServlet`) (which also triggers /backfill) O-Occasional Affects or can be seen by some users regularly or most users rarely S-Minor Blocks non-critical functionality, workarounds exist. T-Defect Bugs, crashes, hangs, security vulnerabilities, or other reported issues.
Projects
None yet
Development

No branches or pull requests

7 participants