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

Retry schedule inexplicably resets on down hosts #5414

Closed
ara4n opened this issue Jun 10, 2019 · 3 comments
Closed

Retry schedule inexplicably resets on down hosts #5414

ara4n opened this issue Jun 10, 2019 · 3 comments

Comments

@ara4n
Copy link
Member

ara4n commented Jun 10, 2019 •
edited
Loading

Looking into why synapse tries to hammer dead hosts, grepping strictly for matrix.breaker.rocks (which doesn't even exist in DNS), I see:

2019-06-07 07:27:09,925 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14734634 - {PUT-O-6724782} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034940241/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 07:27:09,925 - synapse.util.retryutils - 193 - INFO - federation_transaction_transmission_loop-14734634 - Connection to matrix.breaker.rocks was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.)); backoff now 600000
2019-06-07 07:27:09,925 - synapse.federation.transaction_queue - 545 - WARNING - federation_transaction_transmission_loop-14734634 - TX [matrix.breaker.rocks] Failed to send transaction: Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.
2019-06-07 08:40:18,688 - synapse.federation.transaction_queue - 639 - INFO - federation_transaction_transmission_loop-14737319 - TX [matrix.breaker.rocks] {1555034941546} Sending transaction [1555034941546], (PDUs: 0, EDUs: 2)
2019-06-07 08:40:18,688 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:40:18,688 - synapse.http.federation.matrix_federation_agent - 319 - INFO - federation_transaction_transmission_loop-14737319 - Fetching https://matrix.breaker.rocks/.well-known/matrix/server
2019-06-07 08:40:31,104 - synapse.http.federation.matrix_federation_agent - 335 - INFO - federation_transaction_transmission_loop-14737319 - Error fetching https://matrix.breaker.rocks/.well-known/matrix/server: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.
2019-06-07 08:40:31,130 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:40:51,214 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:40:56,517 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:40:56,528 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:41:01,140 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:41:15,828 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:41:15,842 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:41:15,874 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:42:16,142 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:42:16,176 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:42:16,302 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:43:24,825 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:43:24,837 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:43:24,861 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:44:21,256 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:44:21,271 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:44:21,299 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:45:30,958 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:45:30,971 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:45:30,996 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:46:42,413 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:46:42,426 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:46:42,449 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:47:54,575 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:47:54,589 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:47:54,614 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:49:02,037 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:49:02,049 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:49:02,076 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:50:08,688 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/; timeout 60.000000s
2019-06-07 08:50:09,165 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14737319 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:50:12,048 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14737319 - {PUT-O-6726087} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034941546/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:50:12,049 - synapse.util.retryutils - 193 - INFO - federation_transaction_transmission_loop-14737319 - Connection to matrix.breaker.rocks was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.)); backoff now 0
2019-06-07 08:50:12,049 - synapse.federation.transaction_queue - 545 - WARNING - federation_transaction_transmission_loop-14737319 - TX [matrix.breaker.rocks] Failed to send transaction: Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.
2019-06-07 08:50:16,429 - synapse.federation.transaction_queue - 639 - INFO - federation_transaction_transmission_loop-14748396 - TX [matrix.breaker.rocks] {1555034946548} Sending transaction [1555034946548], (PDUs: 0, EDUs: 2)
2019-06-07 08:50:16,429 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:50:18,002 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:50:21,297 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:50:25,345 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:50:25,364 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:50:25,391 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:50:45,220 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:50:45,232 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:50:45,256 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:52:04,258 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:52:04,273 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:52:04,305 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:53:13,948 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:53:13,966 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:53:13,993 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:54:18,914 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:54:18,927 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:54:18,953 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:55:34,593 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:55:34,612 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:55:34,637 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:56:31,716 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:56:31,728 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:56:31,755 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:57:46,862 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:57:46,877 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:57:46,900 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:58:41,336 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:58:41,350 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:58:41,376 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:59:48,220 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/; timeout 60.000000s
2019-06-07 08:59:48,235 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14748396 - Connecting to matrix.breaker.rocks:8448
2019-06-07 08:59:48,258 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14748396 - {PUT-O-6731089} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034946548/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 08:59:48,258 - synapse.util.retryutils - 193 - INFO - federation_transaction_transmission_loop-14748396 - Connection to matrix.breaker.rocks was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.)); backoff now 600000
2019-06-07 08:59:48,258 - synapse.federation.transaction_queue - 545 - WARNING - federation_transaction_transmission_loop-14748396 - TX [matrix.breaker.rocks] Failed to send transaction: Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.
2019-06-07 09:12:56,801 - synapse.federation.transaction_queue - 639 - INFO - federation_transaction_transmission_loop-14751434 - TX [matrix.breaker.rocks] {1555034947964} Sending transaction [1555034947964], (PDUs: 0, EDUs: 2)
2019-06-07 09:12:56,801 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:12:57,390 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:13:14,799 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:13:19,986 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:13:19,998 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:13:20,025 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:13:33,782 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:13:33,794 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:13:33,816 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:14:50,620 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:14:50,633 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:14:50,659 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:16:02,277 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:16:02,291 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:16:02,314 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:17:20,505 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:17:20,520 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:17:20,553 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:18:41,049 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:18:41,069 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:18:41,097 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:19:48,908 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:19:48,920 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:19:48,942 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:20:57,487 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:20:57,498 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:20:57,522 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:21:54,488 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:21:54,534 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:22:09,771 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:23:32,056 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/; timeout 60.000000s
2019-06-07 09:23:32,068 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14751434 - Connecting to matrix.breaker.rocks:8448
2019-06-07 09:23:32,091 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14751434 - {PUT-O-6732506} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034947964/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 09:23:32,091 - synapse.util.retryutils - 193 - INFO - federation_transaction_transmission_loop-14751434 - Connection to matrix.breaker.rocks was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.)); backoff now 3000000
2019-06-07 09:23:32,092 - synapse.federation.transaction_queue - 545 - WARNING - federation_transaction_transmission_loop-14751434 - TX [matrix.breaker.rocks] Failed to send transaction: Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.
2019-06-07 10:59:06,449 - synapse.federation.transaction_queue - 639 - INFO - federation_transaction_transmission_loop-14769375 - TX [matrix.breaker.rocks] {1555034955358} Sending transaction [1555034955358], (PDUs: 0, EDUs: 2)
2019-06-07 10:59:06,449 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 10:59:06,449 - synapse.http.federation.matrix_federation_agent - 319 - INFO - federation_transaction_transmission_loop-14769375 - Fetching https://matrix.breaker.rocks/.well-known/matrix/server
2019-06-07 10:59:23,100 - synapse.http.federation.matrix_federation_agent - 335 - INFO - federation_transaction_transmission_loop-14769375 - Error fetching https://matrix.breaker.rocks/.well-known/matrix/server: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.
2019-06-07 10:59:23,171 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 10:59:41,781 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 10:59:45,793 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 10:59:45,831 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 10:59:47,648 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:00:08,684 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:00:08,698 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:00:08,728 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:01:26,340 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:01:26,351 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:01:26,375 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:02:29,277 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:02:29,291 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:02:29,322 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:03:50,561 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:03:50,573 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:03:50,597 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:04:58,961 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:04:58,975 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:04:59,000 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:05:59,864 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:05:59,877 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:05:59,900 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:07:09,485 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:07:09,497 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:07:09,520 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:08:28,547 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:08:28,563 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:08:28,587 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:09:49,201 - synapse.http.matrixfederationclient - 304 - INFO - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Sending request: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/; timeout 60.000000s
2019-06-07 11:09:49,215 - synapse.http.federation.matrix_federation_agent - 369 - INFO - federation_transaction_transmission_loop-14769375 - Connecting to matrix.breaker.rocks:8448
2019-06-07 11:09:49,240 - synapse.http.matrixfederationclient - 385 - WARNING - federation_transaction_transmission_loop-14769375 - {PUT-O-6739918} [matrix.breaker.rocks] Request failed: PUT matrix://matrix.breaker.rocks/_matrix/federation/v1/send/1555034955358/: DNSLookupError('no results for hostname lookup: matrix.breaker.rocks',)
2019-06-07 11:09:49,240 - synapse.util.retryutils - 193 - INFO - federation_transaction_transmission_loop-14769375 - Connection to matrix.breaker.rocks was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: DNSLookupError: DNS lookup failed: no results for hostname lookup: matrix.breaker.rocks.)); backoff now 0

It's very unclear as to why the backoff keeps resetting to 0.

This particular log sequence was on 0.99.3 or 0.99.4.

(xref #1404)
@ara4n
Copy link
Member Author

ara4n commented Jun 10, 2019

here's another weirdness from v1.0.0-rc1:

2019-06-10 14:33:47,725 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-4327} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190: TimeoutError('',)
2019-06-10 14:34:45,027 - synapse.http.matrixfederationclient - 384 - INFO -  - {PUT-O-4327} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190; timeout 60.000000s
2019-06-10 14:34:45,038 - synapse.http.federation.matrix_federation_agent - 373 - INFO - None - Connecting to matrix.tp.mu:8448
2019-06-10 14:35:15,062 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-4327} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190: TimeoutError('',)
2019-06-10 14:36:25,286 - synapse.http.matrixfederationclient - 384 - INFO -  - {PUT-O-4327} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190; timeout 60.000000s
2019-06-10 14:36:25,299 - synapse.http.federation.matrix_federation_agent - 373 - INFO - None - Connecting to matrix.tp.mu:8448
2019-06-10 14:36:55,327 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-4327} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190: TimeoutError('',)
2019-06-10 14:38:04,766 - synapse.http.matrixfederationclient - 384 - INFO -  - {PUT-O-4327} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190; timeout 60.000000s
2019-06-10 14:38:04,787 - synapse.http.federation.matrix_federation_agent - 373 - INFO - None - Connecting to matrix.tp.mu:8448
2019-06-10 14:38:34,815 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-4327} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902927190: TimeoutError('',)
2019-06-10 14:38:34,815 - synapse.util.retryutils - 193 - INFO -  - Connection to matrix.tp.mu was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: TimeoutError: User timeout caused connection failure.)); backoff now 86400000
2019-06-10 14:38:34,815 - synapse.federation.sender.per_destination_queue - 310 - WARNING -  - TX [matrix.tp.mu] Failed to send transaction: Failed to send request: TimeoutError: User timeout caused connection failure.
2019-06-10 14:40:48,555 - synapse.federation.sender.transaction_manager - 87 - INFO - federation_transaction_transmission_loop-12504 - TX [matrix.tp.mu] {1559902936965} Sending transaction [1559902936965], (PDUs: 0, EDUs: 2)
2019-06-10 14:40:48,556 - synapse.http.matrixfederationclient - 384 - INFO - federation_transaction_transmission_loop-12504 - {PUT-O-14168} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965; timeout 60.000000s
2019-06-10 14:40:49,380 - synapse.http.federation.matrix_federation_agent - 373 - INFO - federation_transaction_transmission_loop-12504 - Connecting to matrix.tp.mu:8448
2019-06-10 14:41:39,599 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-14168} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965: TimeoutError('',)
2019-06-10 14:41:44,181 - synapse.http.matrixfederationclient - 384 - INFO -  - {PUT-O-14168} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965; timeout 60.000000s
2019-06-10 14:41:44,215 - synapse.http.federation.matrix_federation_agent - 373 - INFO - None - Connecting to matrix.tp.mu:8448
2019-06-10 14:42:14,285 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-14168} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965: TimeoutError('',)
2019-06-10 14:42:36,464 - synapse.http.matrixfederationclient - 384 - INFO -  - {PUT-O-14168} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965; timeout 60.000000s
2019-06-10 14:42:36,482 - synapse.http.federation.matrix_federation_agent - 373 - INFO - None - Connecting to matrix.tp.mu:8448
2019-06-10 14:43:06,513 - synapse.http.matrixfederationclient - 465 - WARNING -  - {PUT-O-14168} [matrix.tp.mu] Request failed: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965: TimeoutError('',)
2019-06-10 14:44:30,018 - synapse.http.matrixfederationclient - 384 - INFO -  - {PUT-O-14168} [matrix.tp.mu] Sending request: PUT matrix://matrix.tp.mu/_matrix/federation/v1/send/1559902936965; timeout 60.000000s
2019-06-10 14:44:30,032 - synapse.http.federation.matrix_federation_agent - 373 - INFO - None - Connecting to matrix.tp.mu:8448

Despite declaring 'backoff now 86400000', it promptly then starts a new retry cycle on a new transaction immediately afterwards :|

@ara4n ara4n mentioned this issue Jun 10, 2019
Closed
@richvdh
Copy link
Member

richvdh commented Jun 12, 2019 •
edited
Loading

key lookups are exempt from the backoff, so I don't think the retry schedule is actually being reset here. Hence, closing in favour of #5413

@richvdh richvdh closed this as completed Jun 12, 2019
@richvdh
Copy link
Member

richvdh commented Jun 12, 2019

(there were some fixes to the retry logic in 1.0, notably #5335/#5340, so the logs from 0.99.4 are probably red herrings)

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ara4n @richvdh