search

matrix-org / synapse

Synapse: Matrix homeserver written in Python/Twisted.
https://matrix-org.github.io/synapse
Apache License 2.0
11.82k stars 2.13k forks source link

Synapse sends stack trace as error message over federation #6582

Open Bubu opened 4 years ago

Bubu commented 4 years ago

Description

Synapse 1.7.1 sends stack tarce over fedaration as error message. It begins like this:

Dec 20 12:57:52 bubu synapse[125805]: 2019-12-20 12:57:52,138 - synapse.federation.sender.transaction_manager - 149 - WARNING - federation_transaction_transmission_loop-1606 - TX [<foreign server>] {1576842828228} Remote returned error for $15768430190XSQqk:bubu1.eu: {'error': 'FirstError[#0, [Failure instance: Traceback: <class \'psycopg2.errors.UniqueViolation\'>: duplicate key value violates unique constraint "current_state_events_event_id_key"\nDETAIL:  Key (event_id)=($1561762643543412lzqRA:matrix.org) already exists.

Following are python path installation details of the sending server. While these are not super secret, it's still some sort of information disclosure about the local installation that shouldn't be send to other servers.

Version information

If not matrix.org:

anoadragon453 commented 3 years ago

This is still a problem. Someone just got a stack trace from psycopg2 off my server when my disk was full:

2021-02-20 00:08:18,711 - synapse.federation.sender.transaction_manager - 171 - WARNING - federation_transaction_transmission_loop-12517- TX [amorgan.xyz] {1613774707273} Remote returned error for $I7Zshd4MldQC9hh3bqo0-qYt7Zx7S5N1j2K-H9_Y-ok: {'error': 'Error fetching missing prev_events for $I7Zshd4MldQC9hh3bqo0-qYt7Zx7S5N1j2K-H9_Y-ok: FirstError[#0, [Failure instance: Traceback: <class \'psycopg2.errors.DiskFull\'>: could not extend file "pg_tblspc/263300/PG_10_201707211/68701/722826.10": No space left on device\nHINT:  Check free disk space.\n\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/internet/defer.py:654:_runCallbacks\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/internet/defer.py:1475:gotResult\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/internet/defer.py:1416:_inlineCallbacks\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/python/failure.py:512:throwExceptionIntoGenerator\n--- <exception caught here> ---\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/persist_events.py:172:handle_queue_loop\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/persist_events.py:324:persisting_queue\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/persist_events.py:532:_persist_events\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/databases/main/events.py:171:_persist_events_and_state_updates\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:668:runInteraction\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:751:runWithConnection\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/python/threadpool.py:250:inContext\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/python/threadpool.py:266:<lambda>\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/python/context.py:122:callWithContext\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/python/context.py:85:callWithContext\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/enterprise/adbapi.py:306:_runWithConnection\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/python/compat.py:464:reraise\n/home/synapse/synapse/env/lib/python3.8/site-packages/twisted/enterprise/adbapi.py:297:_runWithConnection\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:746:inner_func\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:540:new_transaction\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/logging/utils.py:70:wrapped\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/databases/main/events.py:372:_persist_events_txn\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/databases/main/events.py:1312:_store_event_txn\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:904:simple_insert_many_txn\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:276:execute_batch\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:321:_do_execute\n/home/synapse/synapse/env/lib/python3.8/site-packages/synapse/storage/database.py:276:<lambda>\n/home/synapse/synapse/env/lib/python3.8/site-packages/psycopg2/extras.py:1206:execute_batch\n]]'}

This isn't ideal as it leaks metadata about your server (including where Synapse is installed to).

scottwallacesh commented 3 years ago

I'm seeing remote stack traces in my server logs which made me panic until I realised what was going on and found this issue.

2021-09-20T14:19:10.428518897+01:00 2021-09-20 14:19:10,427 - synapse.storage.txn - 561 - WARNING - GET-520092- [TXN OPERROR] {get_oldest_event_ids_with_depth_in_room-19f2dc} could not resize shared memory segment "/PostgreSQL.2138012727" to 16777216 bytes: No space left on device
2021-09-20T14:19:10.428589091+01:00  0/5
2021-09-20T14:19:11.480396377+01:00 2021-09-20 14:19:11,480 - synapse.storage.txn - 561 - WARNING - GET-520092- [TXN OPERROR] {get_oldest_event_ids_with_depth_in_room-19f2dc} could not resize shared memory segment "/PostgreSQL.1337643214" to 16777216 bytes: No space left on device
2021-09-20T14:19:11.480483892+01:00  1/5
2021-09-20T14:19:12.538961189+01:00 2021-09-20 14:19:12,538 - synapse.storage.txn - 561 - WARNING - GET-520092- [TXN OPERROR] {get_oldest_event_ids_with_depth_in_room-19f2dc} could not resize shared memory segment "/PostgreSQL.1964615389" to 16777216 bytes: No space left on device
2021-09-20T14:19:12.539032361+01:00  2/5
2021-09-20T14:19:13.603291665+01:00 2021-09-20 14:19:13,602 - synapse.storage.txn - 561 - WARNING - GET-520092- [TXN OPERROR] {get_oldest_event_ids_with_depth_in_room-19f2dc} could not resize shared memory segment "/PostgreSQL.1952846745" to 16777216 bytes: No space left on device
2021-09-20T14:19:13.603354455+01:00  3/5
2021-09-20T14:19:14.659793897+01:00 2021-09-20 14:19:14,659 - synapse.storage.txn - 561 - WARNING - GET-520092- [TXN OPERROR] {get_oldest_event_ids_with_depth_in_room-19f2dc} could not resize shared memory segment "/PostgreSQL.1117256494" to 16777216 bytes: No space left on device
2021-09-20T14:19:14.659879386+01:00  4/5
2021-09-20T14:19:15.753295422+01:00 2021-09-20 14:19:15,752 - synapse.storage.txn - 561 - WARNING - GET-520092- [TXN OPERROR] {get_oldest_event_ids_with_depth_in_room-19f2dc} could not resize shared memory segment "/PostgreSQL.1588250745" to 16777216 bytes: No space left on device
2021-09-20T14:19:15.753425053+01:00  5/5
2021-09-20T14:19:17.823706180+01:00 2021-09-20 14:19:15,754 - synapse.http.server - 93 - ERROR - GET-520092- Failed handle request via 'RoomMessageListRestServlet': <XForwardedForRequest at 0x7f0b3edcb7c0 method='GET' uri='/_matrix/client/r0/rooms/[REDACTED]/messages?from=[REDACTED]&limit=20&dir=b&filter=%7B%22lazy_load_members%22%3Atrue%7D' clientproto='HTTP/1.1' site='8008'>
2021-09-20T14:19:17.823807734+01:00 Traceback (most recent call last):
2021-09-20T14:19:17.823849641+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/http/server.py", line 258, in _async_render_wrapper
2021-09-20T14:19:17.823887566+01:00     callback_return = await self._async_render(request)
2021-09-20T14:19:17.823915783+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/http/server.py", line 446, in _async_render
2021-09-20T14:19:17.823948052+01:00     callback_return = await raw_callback_return
2021-09-20T14:19:17.823985837+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/rest/client/room.py", line 537, in on_GET
2021-09-20T14:19:17.824017128+01:00     msgs = await self.pagination_handler.get_messages(
2021-09-20T14:19:17.824047091+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/handlers/pagination.py", line 396, in get_messages
2021-09-20T14:19:17.824110021+01:00     await self.hs.get_federation_handler().maybe_backfill(
2021-09-20T14:19:17.824150042+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/handlers/federation.py", line 133, in maybe_backfill
2021-09-20T14:19:17.824177840+01:00     return await self._maybe_backfill_inner(room_id, current_depth, limit)
2021-09-20T14:19:17.824208641+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/handlers/federation.py", line 139, in _maybe_backfill_inner
2021-09-20T14:19:17.824235322+01:00     await self.store.get_oldest_event_ids_with_depth_in_room(room_id)
2021-09-20T14:19:17.824261514+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/databases/main/event_federation.py", line 722, in get_oldest_event_ids_with_depth_in_room
2021-09-20T14:19:17.824290429+01:00     return await self.db_pool.runInteraction(
2021-09-20T14:19:17.824315993+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/database.py", line 686, in runInteraction
2021-09-20T14:19:17.824354337+01:00     result = await self.runWithConnection(
2021-09-20T14:19:17.824382205+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/database.py", line 791, in runWithConnection
2021-09-20T14:19:17.824410143+01:00     return await make_deferred_yieldable(
2021-09-20T14:19:17.824437382+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/python/threadpool.py", line 238, in inContext
2021-09-20T14:19:17.824466228+01:00     result = inContext.theWork()  # type: ignore[attr-defined]
2021-09-20T14:19:17.824502338+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/python/threadpool.py", line 254, in <lambda>
2021-09-20T14:19:17.824539774+01:00     inContext.theWork = lambda: context.call(  # type: ignore[attr-defined]
2021-09-20T14:19:17.824573579+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/python/context.py", line 118, in callWithContext
2021-09-20T14:19:17.824617791+01:00     return self.currentContext().callWithContext(ctx, func, *args, **kw)
2021-09-20T14:19:17.824657532+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/python/context.py", line 83, in callWithContext
2021-09-20T14:19:17.824691826+01:00     return func(*args, **kw)
2021-09-20T14:19:17.824727377+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/enterprise/adbapi.py", line 293, in _runWithConnection
2021-09-20T14:19:17.824766001+01:00     compat.reraise(excValue, excTraceback)
2021-09-20T14:19:17.824800993+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/python/deprecate.py", line 298, in deprecatedFunction
2021-09-20T14:19:17.824835775+01:00     return function(*args, **kwargs)
2021-09-20T14:19:17.824884876+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/python/compat.py", line 404, in reraise
2021-09-20T14:19:17.824920427+01:00     raise exception.with_traceback(traceback)
2021-09-20T14:19:17.824948854+01:00   File "/usr/local/lib/python3.8/site-packages/twisted/enterprise/adbapi.py", line 284, in _runWithConnection
2021-09-20T14:19:17.824988525+01:00     result = func(conn, *args, **kw)
2021-09-20T14:19:17.825023029+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/database.py", line 786, in inner_func
2021-09-20T14:19:17.825063189+01:00     return func(db_conn, *args, **kwargs)
2021-09-20T14:19:17.825110963+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/database.py", line 554, in new_transaction
2021-09-20T14:19:17.825155105+01:00     r = func(cursor, *args, **kwargs)
2021-09-20T14:19:17.825204904+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/databases/main/event_federation.py", line 718, in get_oldest_event_ids_with_depth_in_room_txn
2021-09-20T14:19:17.825248347+01:00     txn.execute(sql, (room_id, False))
2021-09-20T14:19:17.825289136+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/database.py", line 298, in execute
2021-09-20T14:19:17.825320287+01:00     self._do_execute(self.txn.execute, sql, *args)
2021-09-20T14:19:17.825366524+01:00   File "/usr/local/lib/python3.8/site-packages/synapse/storage/database.py", line 331, in _do_execute
2021-09-20T14:19:17.825402214+01:00     return func(sql, *args)
2021-09-20T14:19:17.825434133+01:00 psycopg2.errors.DiskFull: could not resize shared memory segment "/PostgreSQL.1588250745" to 16777216 bytes: No space left on device