search

element-hq / synapse

Synapse: Matrix homeserver written in Python/Twisted.
https://element-hq.github.io/synapse
GNU Affero General Public License v3.0
1.64k stars 205 forks source link

Unhandled Error: doWrite called on a twisted.internet.udp.Port #4727

Open matrixbot opened 11 months ago

matrixbot commented 11 months ago

This issue has been migrated from #4727.

I've saw this message in my error log:

twisted: [] Unhandled Error
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/python/log.py", line 103, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/python/log.py", line 86, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
--- <exception caught here> ---
  File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/posixbase.py", line 619, in _doReadOrWrite
    why = selectable.doWrite()
  File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/base.py", line 1192, in doWrite
    "doWrite called on a %s" % reflect.qual(self.__class__))
builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port

Version information

jivanpal commented 4 days ago

I am occasionally/rarely getting bursts of these "CRITICAL" errors, also.

Current Synapse version: 1.120.0

Here is an excerpt of logs from the start of a 60-minute period in which my homeserver logged 265 such errors, and was unresponsive (not federating swiftly and not responsive to clients) for about 35 minutes in the middle of this period (first CRITICAL message at 2024-11-30 00:00, last at 2024-11-30 00:58, server was extremely unresponsive from approx. 2024-11-30 00:15 to 2024-11-30 00:50). The errors occurred in bursts of as many as 64 sequential errors with no intervening activity. The total 265 errors occurred in 57 such bursts. 5 of the bursts had 15 or more errors each, and the remaining 52 bursts had at most 6 errors each. This excerpt contains the first 3 bursts that were logged, which consisted of 1, 6, and 5 sequential errors, respectively:

Output is from grep -FnC15 CRITICAL, so each line begins with its line number in the log file. 

1957-2024-11-30 00:00:20,531 - synapse.access.http.8008 - 472 - INFO - GET-323199 - 2a01:7e00:e000:802:64:6f97:c34e:f732 - 8008 - {matrix.co.ua} Processed request: 2.303sec/0.940sec (0.005sec, 0.000sec) (0.000sec/0.000sec/0) 852B 200 "GET /_matrix/federation/v1/event/%24wJT92C0UmrC8wGLOv1KEujiHj1MmhiWyZXahY0dHmB8 HTTP/1.1" "Synapse/1.117.0" [0 dbevts]
1958-2024-11-30 00:00:20,532 - synapse.access.http.8008 - 472 - INFO - GET-323200 - 2a01:7e00:e000:802:64:6f97:823d:1486 - 8008 - {xavi.lu} Processed request: 2.306sec/0.936sec (0.004sec, 0.004sec) (0.000sec/0.000sec/0) 892B 200 "GET /_matrix/federation/v1/event/%24chiuaxdXgE4M6zWubwpQX-VcFoowwyrsnra35HUqGEQ HTTP/1.1" "Synapse/1.118.0" [0 dbevts]
1959-2024-11-30 00:00:20,534 - synapse.access.http.8008 - 472 - INFO - GET-323201 - 2a01:7e00:e000:802:64:6f97:823d:1486 - 8008 - {xavi.lu} Processed request: 2.307sec/0.934sec (0.005sec, 0.000sec) (0.000sec/0.000sec/0) 1069B 200 "GET /_matrix/federation/v1/event/%24mdcJIOJihOBCf05PNO8vLk5I7soKZObgk_8MS4ZElds HTTP/1.1" "Synapse/1.118.0" [0 dbevts]
1960-2024-11-30 00:00:20,535 - synapse.access.http.8008 - 472 - INFO - GET-323202 - 2a01:7e00:e000:802:64:6f97:823d:1486 - 8008 - {xavi.lu} Processed request: 2.309sec/0.931sec (0.003sec, 0.000sec) (0.000sec/0.000sec/0) 1129B 200 "GET /_matrix/federation/v1/event/%24SOL1brfmx1_OQ5nqeXjxZrJtz6myuBKnSNHebOHMcn8 HTTP/1.1" "Synapse/1.118.0" [0 dbevts]
1961-2024-11-30 00:00:20,536 - synapse.access.http.8008 - 472 - INFO - PUT-323205 - 2a01:7e00:e000:802:64:6f97:9e27:c985 - 8008 - {uwu.sulian.eu} Processed request: 2.309sec/0.928sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/47DEQpj8HBSa-_TImW-5JCeuQeRkm5NMpJWZG3hSuFU HTTP/1.1" "Conduwuit/0.5.0 (b94eeb9-dirty)" [0 dbevts]
1962-2024-11-30 00:00:20,537 - synapse.access.http.8008 - 472 - INFO - GET-323206 - 2a01:7e00:e000:802:64:6f97:421d:885b - 8008 - {discuss.online} Processed request: 2.311sec/0.925sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 849B 200 "GET /_matrix/federation/v1/event/%24nUuqdLpI0_SgFoWKyZxzqUPrgrN23tuVamFuMgjC43M HTTP/1.1" "Synapse/1.119.0" [0 dbevts]
1963-2024-11-30 00:00:20,538 - synapse.access.http.8008 - 472 - INFO - PUT-323207 - 2a01:7e00:e000:802:64:6f97:5166:f99c - 8008 - {nexy7574.co.uk} Processed request: 2.310sec/0.923sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 11B 200 "PUT /_matrix/federation/v1/send/47DEQpj8HBSa-_TImW-5JCeuQeRkm5NMpJWZG3hSuFU HTTP/1.1" "Conduwuit/0.5.0 (b94eeb9)" [0 dbevts]
1964-2024-11-30 00:00:20,548 - synapse.storage.databases.main.event_push_actions - 1599 - INFO - rotate_notifs-4961 - Rotating notifications up to: 3671002
1965-2024-11-30 00:00:20,559 - synapse.storage.databases.main.event_push_actions - 1685 - INFO - rotate_notifs-4961 - Rotating notifications, handling 0 rows
1966-2024-11-30 00:00:20,786 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-225929 - {PUT-O-236164} [mtx.liftm.de] Completed request: 200 OK in 96.93 secs, got 11 bytes - PUT matrix-federation://mtx.liftm.de/_matrix/federation/v1/send/1732776182811
1967-2024-11-30 00:00:20,786 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-225929 - TX [mtx.liftm.de] {1732776182811} got 200 response
1968-2024-11-30 00:00:20,787 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-225929 - TX [mtx.liftm.de] {1732776185100} Sending transaction [1732776185100], (PDUs: 0, EDUs: 3)
1969-2024-11-30 00:00:20,911 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-226329 - {PUT-O-236189} [imagisphe.re] Completed request: 200 OK in 96.87 secs, got 11 bytes - PUT matrix-federation://imagisphe.re/_matrix/federation/v1/send/1732776182836
1970-2024-11-30 00:00:20,911 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-226329 - TX [imagisphe.re] {1732776182836} got 200 response
1971-2024-11-30 00:00:20,913 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-226329 - TX [imagisphe.re] {1732776185101} Sending transaction [1732776185101], (PDUs: 0, EDUs: 3)
1972:2024-11-30 00:00:20,982 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
1973-Traceback (most recent call last):
1974-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
1975-    return callWithContext({"system": lp}, func, *args, **kw)
1976-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
1977-    return context.call({ILogContext: newCtx}, func, *args, **kw)
1978-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
1979-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
1980-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
1981-    return func(*args, **kw)
1982---- <exception caught here> ---
1983-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
1984-    why = selectable.doWrite()
1985-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
1986-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
1987-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
--
4537-2024-11-30 00:00:47,750 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-224887 - TX [m4tr1x.mooo.com] {1732776184493} got 200 response
4538-2024-11-30 00:00:47,807 - synapse.http.matrixfederationclient - 364 - INFO - PerspectivesKeyFetcher-3257 - {POST-O-237879} [matrix.org] Completed request: 200 OK in 44.55 secs, got 546 bytes - POST matrix-federation://matrix.org/_matrix/key/v2/query
4539-2024-11-30 00:00:47,811 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-226865 - {PUT-O-237717} [matrix.radiocorax.de] Completed request: 200 OK in 54.95 secs, got 11 bytes - PUT matrix-federation://matrix.radiocorax.de/_matrix/federation/v1/send/1732776184354
4540-2024-11-30 00:00:47,811 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-226865 - TX [matrix.radiocorax.de] {1732776184354} got 200 response
4541-2024-11-30 00:00:47,812 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-226865 - TX [matrix.radiocorax.de] {1732776185843} Sending transaction [1732776185843], (PDUs: 1, EDUs: 2)
4542-2024-11-30 00:00:47,819 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-227069 - {PUT-O-235997} [msg-server.vlad-pal.net] Completed request: 200 OK in 149.71 secs, got 11 bytes - PUT matrix-federation://msg-server.vlad-pal.net/_matrix/federation/v1/send/1732776182646
4543-2024-11-30 00:00:47,820 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-227069 - TX [msg-server.vlad-pal.net] {1732776182646} got 200 response
4544-2024-11-30 00:00:47,821 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-227069 - TX [msg-server.vlad-pal.net] {1732776185844} Sending transaction [1732776185844], (PDUs: 1, EDUs: 3)
4545-2024-11-30 00:00:47,823 - synapse.http.federation.well_known_resolver - 260 - INFO - federation_transaction_transmission_loop-227069 - Fetching https://msg-server.vlad-pal.net/.well-known/matrix/server
4546-2024-11-30 00:00:47,870 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-224528 - {PUT-O-237857} [bitcoinlizard.net] Completed request: 200 OK in 52.80 secs, got 11 bytes - PUT matrix-federation://bitcoinlizard.net/_matrix/federation/v1/send/1732776184494
4547-2024-11-30 00:00:47,870 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-224528 - TX [bitcoinlizard.net] {1732776184494} got 200 response
4548-2024-11-30 00:00:47,871 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-224528 - TX [bitcoinlizard.net] {1732776185845} Sending transaction [1732776185845], (PDUs: 1, EDUs: 2)
4549-2024-11-30 00:00:47,919 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-227006 - {PUT-O-237598} [tejat.net] Completed request: 200 OK in 58.07 secs, got 11 bytes - PUT matrix-federation://tejat.net/_matrix/federation/v1/send/1732776184237
4550-2024-11-30 00:00:47,919 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-227006 - TX [tejat.net] {1732776184237} got 200 response
4551-2024-11-30 00:00:47,920 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-227006 - TX [tejat.net] {1732776185846} Sending transaction [1732776185846], (PDUs: 1, EDUs: 2)
4552:2024-11-30 00:00:48,002 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4553-Traceback (most recent call last):
4554-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4555-    return callWithContext({"system": lp}, func, *args, **kw)
4556-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4557-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4558-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4559-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4560-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4561-    return func(*args, **kw)
4562---- <exception caught here> ---
4563-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4564-    why = selectable.doWrite()
4565-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4566-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4567-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4568-
4569:2024-11-30 00:00:48,004 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4570-Traceback (most recent call last):
4571-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4572-    return callWithContext({"system": lp}, func, *args, **kw)
4573-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4574-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4575-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4576-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4577-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4578-    return func(*args, **kw)
4579---- <exception caught here> ---
4580-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4581-    why = selectable.doWrite()
4582-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4583-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4584-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4585-
4586:2024-11-30 00:00:48,005 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4587-Traceback (most recent call last):
4588-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4589-    return callWithContext({"system": lp}, func, *args, **kw)
4590-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4591-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4592-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4593-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4594-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4595-    return func(*args, **kw)
4596---- <exception caught here> ---
4597-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4598-    why = selectable.doWrite()
4599-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4600-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4601-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4602-
4603:2024-11-30 00:00:48,006 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4604-Traceback (most recent call last):
4605-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4606-    return callWithContext({"system": lp}, func, *args, **kw)
4607-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4608-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4609-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4610-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4611-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4612-    return func(*args, **kw)
4613---- <exception caught here> ---
4614-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4615-    why = selectable.doWrite()
4616-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4617-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4618-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4619-
4620:2024-11-30 00:00:48,007 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4621-Traceback (most recent call last):
4622-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4623-    return callWithContext({"system": lp}, func, *args, **kw)
4624-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4625-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4626-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4627-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4628-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4629-    return func(*args, **kw)
4630---- <exception caught here> ---
4631-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4632-    why = selectable.doWrite()
4633-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4634-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4635-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4636-
4637:2024-11-30 00:00:48,008 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4638-Traceback (most recent call last):
4639-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4640-    return callWithContext({"system": lp}, func, *args, **kw)
4641-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4642-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4643-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4644-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4645-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4646-    return func(*args, **kw)
4647---- <exception caught here> ---
4648-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4649-    why = selectable.doWrite()
4650-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4651-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4652-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
--
4867-2024-11-30 00:00:49,776 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-225931 - TX [matrix.hopfenspace.org] {1732776185913} Sending transaction [1732776185913], (PDUs: 1, EDUs: 3)
4868-2024-11-30 00:00:49,918 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-225845 - {PUT-O-236315} [indoor.app] Completed request: 200 OK in 121.54 secs, got 11 bytes - PUT matrix-federation://indoor.app/_matrix/federation/v1/send/1732776182962
4869-2024-11-30 00:00:49,918 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-225845 - TX [indoor.app] {1732776182962} got 200 response
4870-2024-11-30 00:00:49,920 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-225845 - TX [indoor.app] {1732776185914} Sending transaction [1732776185914], (PDUs: 1, EDUs: 3)
4871-2024-11-30 00:00:49,927 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-226913 - {PUT-O-237689} [spaghetti.host] Completed request: 200 OK in 57.32 secs, got 11 bytes - PUT matrix-federation://spaghetti.host/_matrix/federation/v1/send/1732776184326
4872-2024-11-30 00:00:49,927 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-226913 - TX [spaghetti.host] {1732776184326} got 200 response
4873-2024-11-30 00:00:49,928 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-226913 - TX [spaghetti.host] {1732776185915} Sending transaction [1732776185915], (PDUs: 1, EDUs: 2)
4874-2024-11-30 00:00:49,931 - synapse.http.federation.well_known_resolver - 260 - INFO - federation_transaction_transmission_loop-226913 - Fetching https://spaghetti.host/.well-known/matrix/server
4875-2024-11-30 00:00:49,935 - synapse.http.matrixfederationclient - 343 - WARNING - federation_transaction_transmission_loop-227165 - {PUT-O-237874} [synapse.getcom.de] Error reading response PUT matrix-federation://synapse.getcom.de/_matrix/federation/v1/send/1732776184508: Failed to send request: RuntimeError: Remote server sent Content-Type header of 'text/html; charset=UTF-8', not 'application/json'
4876-2024-11-30 00:00:49,936 - synapse.federation.sender.per_destination_queue - 421 - WARNING - federation_transaction_transmission_loop-227165 - TX [synapse.getcom.de] Failed to send transaction: Failed to send request: RuntimeError: Remote server sent Content-Type header of 'text/html; charset=UTF-8', not 'application/json'
4877-2024-11-30 00:00:49,939 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-224564 - {PUT-O-236695} [matrix.wrest.social] Completed request: 200 OK in 114.62 secs, got 11 bytes - PUT matrix-federation://matrix.wrest.social/_matrix/federation/v1/send/1732776183342
4878-2024-11-30 00:00:49,939 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-224564 - TX [matrix.wrest.social] {1732776183342} got 200 response
4879-2024-11-30 00:00:49,941 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-224564 - TX [matrix.wrest.social] {1732776185916} Sending transaction [1732776185916], (PDUs: 1, EDUs: 3)
4880-2024-11-30 00:00:49,964 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-225323 - {PUT-O-237859} [matrix.gridp7.de] Completed request: 200 OK in 53.31 secs, got 110 bytes - PUT matrix-federation://matrix.gridp7.de/_matrix/federation/v1/send/1732776184496
4881-2024-11-30 00:00:49,964 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-225323 - TX [matrix.gridp7.de] {1732776184496} got 200 response
4882:2024-11-30 00:00:50,108 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4883-Traceback (most recent call last):
4884-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4885-    return callWithContext({"system": lp}, func, *args, **kw)
4886-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4887-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4888-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4889-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4890-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4891-    return func(*args, **kw)
4892---- <exception caught here> ---
4893-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4894-    why = selectable.doWrite()
4895-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4896-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4897-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4898-
4899:2024-11-30 00:00:50,113 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4900-Traceback (most recent call last):
4901-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4902-    return callWithContext({"system": lp}, func, *args, **kw)
4903-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4904-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4905-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4906-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4907-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4908-    return func(*args, **kw)
4909---- <exception caught here> ---
4910-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4911-    why = selectable.doWrite()
4912-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4913-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4914-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4915-
4916:2024-11-30 00:00:50,114 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4917-Traceback (most recent call last):
4918-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4919-    return callWithContext({"system": lp}, func, *args, **kw)
4920-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4921-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4922-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4923-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4924-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4925-    return func(*args, **kw)
4926---- <exception caught here> ---
4927-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4928-    why = selectable.doWrite()
4929-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4930-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4931-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4932-
4933:2024-11-30 00:00:50,119 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4934-Traceback (most recent call last):
4935-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4936-    return callWithContext({"system": lp}, func, *args, **kw)
4937-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4938-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4939-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4940-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4941-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4942-    return func(*args, **kw)
4943---- <exception caught here> ---
4944-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4945-    why = selectable.doWrite()
4946-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4947-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4948-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
4949-
4950:2024-11-30 00:00:50,120 - twisted - 279 - CRITICAL - sentinel - Unhandled Error
4951-Traceback (most recent call last):
4952-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 96, in callWithLogger
4953-    return callWithContext({"system": lp}, func, *args, **kw)
4954-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/log.py", line 80, in callWithContext
4955-    return context.call({ILogContext: newCtx}, func, *args, **kw)
4956-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 117, in callWithContext
4957-    return self.currentContext().callWithContext(ctx, func, *args, **kw)
4958-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/python/context.py", line 82, in callWithContext
4959-    return func(*args, **kw)
4960---- <exception caught here> ---
4961-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/posixbase.py", line 486, in _doReadOrWrite
4962-    why = selectable.doWrite()
4963-  File "/opt/venvs/matrix-synapse/lib/python3.9/site-packages/twisted/internet/base.py", line 1339, in doWrite
4964-    raise RuntimeError("doWrite called on a %s" % reflect.qual(self.__class__))
4965-builtins.RuntimeError: doWrite called on a twisted.internet.udp.Port
--