On 11/02/2025 12:47, Michael Rogers via anti-censorship-team wrote:
On 07/02/2025 21:22, Cecylia Bocovich via anti-censorship-team wrote:
On 2025-02-07 12:22, Michael Rogers via anti-censorship-team wrote:
Hi all,
After updating Briar's bridge config to use the current settings from Moat, we're seeing two Snowflake bridges consistently failing in our CI tests. They're the two bridges that use SQS. Here's a snippet from the log:
INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/35/lyrebird": offer created Feb 04, 2025 1:12:34 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/35/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 60e91cfa-a2a0-55db-beb0-7ce6b621d324, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist.Does the queue really not exist, or does this point to some other issue, like the bridges being geoIP restricted or the app needing to pass some extra information to the transport?
Thanks, Michael
Hi Michael,
I've set up some AWS actions to stop allowing API calls when our budget is exceeded, and I saw that it was applied yesterday. I'd been meaning to update this and finally got around to doing that today. The budget action is lifted and it should work again. I was able to get an answer testing it myself. If your CI is using the production SQS deployment, you might see failure due to this budget action being applied, but that will be a 403 Forbidden response.
That said, this 400 response is referring to the ephemeral single-use client queue that is created by the broker at the time of the client poll. I'm guessing that the latency in queue creation was just too great and the broker didn't have time to create the queue before the client gave up looking for it. SQS is a relatively new feature and it is very likely some of our timeouts should be adjusted.
How are your CI tests set up? Snowflake will retry the poll if it doesn't succeed the first time, and I'm wondering if these messages are the actual cause of the failure or just noisy because they ended up the Tor log. In any case, if you are getting a lot of these 400 responses we should tune the timing of this.
Hi Cecylia,
Thanks for following up on this. I've just re-run the CI test and it's still failing with the same error [1], so I wonder if you might be right about the timeouts needing to be adjusted.
The test fires up a Tor instance with one bridge configured and waits for it to bootstrap [2]. We do this for each bridge in the config, giving each bridge five attempts to succeed before considering it to be down.
The bootstrap timeout is 10 minutes for meek bridges and 2 minutes for all other transports, which is usually enough.
Below is the full log output from an attempt to contact one of the SQS bridges in the latest pipeline, in case it's useful. But basically it just repeats the same error message about the SQS queue, with different queue IDs, until it times out. Don't worry about the STATUS line warning, that's logged for all bridges with Lyrebird and doesn't prevent the others from working.
Cheers, Michael
org.briarproject.onionwrapper.BridgeTest > testBridges[33] STANDARD_ERROR Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.BridgeTest testBridges WARNING: Testing Bridge snowflake 192.0.2.5:80 2B280B23E1107BB62ABFC40DDCC8824814F80A72 fingerprint=2B280B23E1107BB62ABFC40DDCC8824814F80A72 sqsqueue=https:// sqs.us-east-1.amazonaws.com/893902434899/snowflake-broker sqscreds=eyJhd3MtYWNjZXNzLWtleS1pZCI6IkFLSUE1QUlGNFdKSlhTN1lIRUczIiwiYXdzLXNlY3JldC1rZXkiOiI3U0RNc0pBNHM1RitXZWJ1L3pMOHZrMFFXV0lsa1c2Y1dOZlVsQ0tRIn0= ice=stun:stun.antisip.com:3478,stun:stun.epygi.com:3478,stun:stun.uls.co.za:3478,stun:stun.voipgate.com:3478,stun:stun.nextcloud.com:3478,stun:stun.bethesda.net:3478,stun:stun.nextcloud.com:443 utls-imitate=hellorandomizedalpn Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper installTorExecutable INFO: Installing Tor binary for x86_64 Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper installLyrebirdExecutable INFO: Installing lyrebird binary for x86_64 Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper start INFO: Starting Tor Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper lambda$waitForTorToStart$0 INFO: Feb 11 12:30:38.716 [notice] Tor 0.4.8.9 (git- af511c6ffaef0884) running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1w, Zlib 1.2.12, Liblzma 5.2.10, Libzstd N/A and Glibc 2.31 as libc. Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper start INFO: Auth cookie created Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Switching to guard context "bridges" (was using "default") Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Opening Socks listener on 127.0.0.1:59061 Feb 11, 2025 12:30:38 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Opened Socks listener connection (ready) on 127.0.0.1:59061 Feb 11, 2025 12:30:39 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: WARN Managed proxy "/builds/briar/onionwrapper/onionwrapper- java/test.tmp/33/lyrebird" wrote a STATUS line without TRANSPORT: "TYPE=version IMPLEMENTATION=\"lyrebird\" VERSION=\"0.5.0\"" Feb 11, 2025 12:30:39 PM org.briarproject.onionwrapper.AbstractTorWrapper orConnStatus INFO: OR connection LAUNCHED Feb 11, 2025 12:30:39 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Bootstrapped 1% (conn_pt): Connecting to pluggable transport Feb 11, 2025 12:30:39 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Bootstrapped 2% (conn_done_pt): Connected to pluggable transport Feb 11, 2025 12:30:39 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Bootstrapped 10% (conn_done): Connected to a relay Feb 11, 2025 12:30:40 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:30:47 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: ba6ef7b0-e7c0-50b7-95cf-9795a2f671d6, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:30:50 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:30:57 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: b36bd8de-5fd1-56d2-b640-b8fb1aee47b3, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:31:00 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:31:06 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 61bef4d7-d984-5dc1-943c-94f29ccd6ca0, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:31:10 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:31:16 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: b7c29b14-9014-5b3a-a439-fb31d5473a5b, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:31:20 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:31:26 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 09458e52-dbd0-54c6-9bc5-ee779e8d25a7, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:31:30 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:31:36 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: fb8b678a-f8b4-5309-aca0-07afbdd32268, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:31:40 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:31:46 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 78f8d74b-4873-504a-850f-b76e0d02c12b, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:31:50 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:31:56 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 527adb09-0986-5491-9d5f-bb2c4cfde5f0, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:32:00 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:32:06 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 4e2efe2f-de86-5a33-a1a1-9e0a9b03ab52, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:32:10 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:32:16 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 117e9c2d-125c-5902-b871-fc0857d36863, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:32:20 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:32:26 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: e4428a56-83c6-53ef-b6d7-ea73c65f028e, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:32:30 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": offer created Feb 11, 2025 12:32:36 PM org.briarproject.onionwrapper.AbstractTorWrapper message INFO: NOTICE Managed proxy "/builds/briar/onionwrapper/ onionwrapper-java/test.tmp/33/lyrebird": broker failure operation error SQS: GetQueueUrl, https response error StatusCode: 400, RequestID: 61591ece-731d-563e-8110-7eeb36beb75f, AWS.SimpleQueueService.NonExistentQueue: The specified queue does not exist. Feb 11, 2025 12:32:39 PM org.briarproject.onionwrapper.BridgeTest testBridges WARNING: Could not connect to Tor within timeout: Bridge snowflake 192.0.2.5:80 2B280B23E1107BB62ABFC40DDCC8824814F80A72 fingerprint=2B280B23E1107BB62ABFC40DDCC8824814F80A72 sqsqueue=https:// sqs.us-east-1.amazonaws.com/893902434899/snowflake-broker sqscreds=eyJhd3MtYWNjZXNzLWtleS1pZCI6IkFLSUE1QUlGNFdKSlhTN1lIRUczIiwiYXdzLXNlY3JldC1rZXkiOiI3U0RNc0pBNHM1RitXZWJ1L3pMOHZrMFFXV0lsa1c2Y1dOZlVsQ0tRIn0= ice=stun:stun.antisip.com:3478,stun:stun.epygi.com:3478,stun:stun.uls.co.za:3478,stun:stun.voipgate.com:3478,stun:stun.nextcloud.com:3478,stun:stun.bethesda.net:3478,stun:stun.nextcloud.com:443 utls-imitate=hellorandomizedalpn Feb 11, 2025 12:32:39 PM org.briarproject.onionwrapper.AbstractTorWrapper lambda$waitForTorToStart$0 INFO: Tor exited with value 0[1] https://code.briarproject.org/briar/onionwrapper/-/jobs/36898 [2] https://code.briarproject.org/briar/onionwrapper/-/blob/update- bridges-from-moat/onionwrapper-java/src/test/java/org/briarproject/ onionwrapper/BridgeTest.java?ref_type=heads
Well, I should've waited before sending that message, because starting at 12:59 UTC the attempts to bootstrap via SQS bridges succeeded, with only one queue-related error being printed per boostrapping attempt.
Did anything change in the bridge config around that time, or could the queue errors be load-dependent?
Cheers, Michael