I’m noticing a really sharp drop in Traffic Relayed over the last day or so with with NAT type measurement: restricted → restricted = restricted
Most of the hourly counts are: 0 connections, 0 B up, 0 B down. Rare counts in the MB range. Occasional counts in the KB range.
Previously it was much better.
Any other standalone operators seeing this?
My NAT type is unrestricted.
What I see in logs is effect from
Sudden reduction in snowflake-01 bridge bandwidth, 2022-10-04 17:15:
2022/10/03 08:20:07 In the last 1h0m0s, there were 200 connections. Traffic Relayed ↑ 1 GB, ↓ 399 MB.
2022/10/04 08:20:07 In the last 1h0m0s, there were 152 connections. Traffic Relayed ↑ 953 MB, ↓ 161 MB.
2022/10/05 08:20:07 In the last 1h0m0s, there were 51 connections. Traffic Relayed ↑ 147 MB, ↓ 17 MB.
...
2022/10/11 08:53:02 In the last 1h0m0s, there were 21 connections. Traffic Relayed ↑ 22 MB, ↓ 3 MB.
2022/10/12 08:55:57 In the last 1h0m0s, there were 15 connections. Traffic Relayed ↑ 33 MB, ↓ 4 MB.
It happened more than 1 day ago, but I think that with your proxy this event also should be noticeable.
Maybe some other event is overlapping in your case.
I have observed the same behavior on my bridges. Number of clients tend to go to 0.
After i restart the docker container the users are starting to enter again but after some time the number goes to 0 again so i restarted again and again users.
Logs in the last 48 hours from on of the Snowflake bridges can be see below but the behavior i’ve observed on both of them
Container reset 1 : 2022/10/10 06:24:27 → 2022/10/10 08:18:37
Container reset 2: 2022/10/10 21:18:37 → 2022/10/10 22:47:46
Container reset 3: 2022/10/12 09:47:47 → 2022/10/12 11:37:21
2022/10/09 14:24:27 In the last 1h0m0s, there were 10 connections. Traffic Relayed ↑ 57 MB, ↓ 5 MB.
2022/10/09 15:24:27 In the last 1h0m0s, there were 6 connections. Traffic Relayed ↑ 49 MB, ↓ 6 MB.
2022/10/09 16:24:27 In the last 1h0m0s, there were 7 connections. Traffic Relayed ↑ 10 MB, ↓ 458 KB.
2022/10/09 17:24:27 In the last 1h0m0s, there were 7 connections. Traffic Relayed ↑ 40 MB, ↓ 6 MB.
2022/10/09 18:24:27 In the last 1h0m0s, there were 2 connections. Traffic Relayed ↑ 850 KB, ↓ 84 KB.
2022/10/09 19:24:27 In the last 1h0m0s, there were 5 connections. Traffic Relayed ↑ 326 KB, ↓ 112 KB.
2022/10/09 20:24:27 In the last 1h0m0s, there were 4 connections. Traffic Relayed ↑ 13 MB, ↓ 2 MB.
2022/10/09 21:24:27 In the last 1h0m0s, there were 4 connections. Traffic Relayed ↑ 18 MB, ↓ 109 MB.
2022/10/09 22:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/09 23:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 00:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 01:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 02:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 03:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 04:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 05:24:27 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/10 06:24:27 In the last 1h0m0s, there were 1 connections. Traffic Relayed ↑ 1 MB, ↓ 46 KB.
2022/10/10 08:18:37 In the last 1h0m0s, there were 46 connections. Traffic Relayed ↑ 130 MB, ↓ 9 MB.
2022/10/10 09:18:37 In the last 1h0m0s, there were 50 connections. Traffic Relayed ↑ 335 MB, ↓ 49 MB.
2022/10/10 10:18:37 In the last 1h0m0s, there were 40 connections. Traffic Relayed ↑ 255 MB, ↓ 27 MB.
2022/10/10 11:18:37 In the last 1h0m0s, there were 46 connections. Traffic Relayed ↑ 204 MB, ↓ 107 MB.
2022/10/10 12:18:37 In the last 1h0m0s, there were 42 connections. Traffic Relayed ↑ 195 MB, ↓ 56 MB.
2022/10/10 13:18:37 In the last 1h0m0s, there were 39 connections. Traffic Relayed ↑ 143 MB, ↓ 41 MB.
2022/10/10 14:18:37 In the last 1h0m0s, there were 41 connections. Traffic Relayed ↑ 141 MB, ↓ 13 MB.
2022/10/10 15:18:37 In the last 1h0m0s, there were 15 connections. Traffic Relayed ↑ 166 MB, ↓ 16 MB.
2022/10/10 16:18:37 In the last 1h0m0s, there were 20 connections. Traffic Relayed ↑ 60 MB, ↓ 6 MB.
2022/10/10 17:18:37 In the last 1h0m0s, there were 16 connections. Traffic Relayed ↑ 58 MB, ↓ 12 MB.
2022/10/10 18:18:37 In the last 1h0m0s, there were 15 connections. Traffic Relayed ↑ 17 MB, ↓ 8 MB.
2022/10/10 19:18:37 In the last 1h0m0s, there were 15 connections. Traffic Relayed ↑ 53 MB, ↓ 6 MB.
2022/10/10 20:18:37 In the last 1h0m0s, there were 9 connections. Traffic Relayed ↑ 65 MB, ↓ 7 MB.
2022/10/10 21:18:37 In the last 1h0m0s, there were 6 connections. Traffic Relayed ↑ 2 MB, ↓ 73 KB.
2022/10/10 22:47:46 In the last 1h0m0s, there were 54 connections. Traffic Relayed ↑ 264 MB, ↓ 18 MB.
2022/10/10 23:47:46 In the last 1h0m0s, there were 25 connections. Traffic Relayed ↑ 124 MB, ↓ 10 MB.
2022/10/11 00:47:46 In the last 1h0m0s, there were 12 connections. Traffic Relayed ↑ 47 MB, ↓ 3 MB.
2022/10/11 01:47:46 In the last 1h0m0s, there were 5 connections. Traffic Relayed ↑ 159 MB, ↓ 7 MB.
2022/10/11 02:47:47 In the last 1h0m0s, there were 5 connections. Traffic Relayed ↑ 24 MB, ↓ 3 MB.
2022/10/11 03:47:47 In the last 1h0m0s, there were 10 connections. Traffic Relayed ↑ 8 MB, ↓ 541 KB.
2022/10/11 04:47:47 In the last 1h0m0s, there were 31 connections. Traffic Relayed ↑ 127 MB, ↓ 23 MB.
2022/10/11 05:47:47 In the last 1h0m0s, there were 35 connections. Traffic Relayed ↑ 117 MB, ↓ 9 MB.
2022/10/11 06:47:47 In the last 1h0m0s, there were 27 connections. Traffic Relayed ↑ 162 MB, ↓ 21 MB.
2022/10/11 07:47:47 In the last 1h0m0s, there were 21 connections. Traffic Relayed ↑ 112 MB, ↓ 11 MB.
2022/10/11 08:47:47 In the last 1h0m0s, there were 17 connections. Traffic Relayed ↑ 44 MB, ↓ 28 MB.
2022/10/11 09:47:47 In the last 1h0m0s, there were 25 connections. Traffic Relayed ↑ 131 MB, ↓ 19 MB.
2022/10/11 10:47:47 In the last 1h0m0s, there were 24 connections. Traffic Relayed ↑ 40 MB, ↓ 2 MB.
2022/10/11 11:47:47 In the last 1h0m0s, there were 19 connections. Traffic Relayed ↑ 145 MB, ↓ 12 MB.
2022/10/11 12:47:47 In the last 1h0m0s, there were 21 connections. Traffic Relayed ↑ 132 MB, ↓ 11 MB.
2022/10/11 13:47:47 In the last 1h0m0s, there were 7 connections. Traffic Relayed ↑ 9 MB, ↓ 1 MB.
2022/10/11 14:47:47 In the last 1h0m0s, there were 8 connections. Traffic Relayed ↑ 15 MB, ↓ 2 MB.
2022/10/11 15:47:47 In the last 1h0m0s, there were 12 connections. Traffic Relayed ↑ 7 MB, ↓ 1 MB.
2022/10/11 16:47:47 In the last 1h0m0s, there were 7 connections. Traffic Relayed ↑ 32 MB, ↓ 2 MB.
2022/10/11 17:47:47 In the last 1h0m0s, there were 12 connections. Traffic Relayed ↑ 49 MB, ↓ 15 MB.
2022/10/11 18:47:47 In the last 1h0m0s, there were 14 connections. Traffic Relayed ↑ 53 MB, ↓ 7 MB.
2022/10/11 19:47:47 In the last 1h0m0s, there were 12 connections. Traffic Relayed ↑ 19 MB, ↓ 2 MB.
2022/10/11 20:47:47 In the last 1h0m0s, there were 16 connections. Traffic Relayed ↑ 35 MB, ↓ 6 MB.
2022/10/11 21:47:47 In the last 1h0m0s, there were 8 connections. Traffic Relayed ↑ 16 MB, ↓ 2 MB.
2022/10/11 22:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/11 23:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 00:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 01:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 02:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 03:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 04:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 05:47:47 In the last 1h0m0s, there were 1 connections. Traffic Relayed ↑ 22 MB, ↓ 6 MB.
2022/10/12 06:47:47 In the last 1h0m0s, there were 3 connections. Traffic Relayed ↑ 17 MB, ↓ 8 MB.
2022/10/12 07:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 08:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 09:47:47 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/12 11:37:21 In the last 1h0m0s, there were 14 connections. Traffic Relayed ↑ 120 MB, ↓ 7 MB.
2022/10/12 12:37:21 In the last 1h0m0s, there were 26 connections. Traffic Relayed ↑ 120 MB, ↓ 18 MB.
Thanks for this. Perhaps I’ll try a restart of the standalone and see if I get similar results.
Meanwhile @SirNeo, if you look at this issue there is a tip from @cecylia about getting verbose logging on a docker container:
Issue opened here:
Includes verbose log output.
Thanks @Quartermarsh
I started the container with -verbose command and in case i see something strange i will put the logs where the issue was opened.
For me it happened again.
Somehow from advanced logs i observed that the number of clients is 0 because from uknown reasons Snowflake proxy doesn’t receives anymore sdp offers. I just restarted the container and after the account on gitlab will be proved i will post there the logs before/after restart.
The last 8-10 hours looks like this
2022/10/13 20:15:12 Connection successful.
2022/10/13 20:15:12 OnOpen channel
2022/10/13 20:15:13 connected to relay: wss://snowflake.torproject.net/
2022/10/13 20:16:35 OnClose channel
2022/10/13 20:16:35 Traffic throughput (up|down): 16 MB|1 MB -- (4530 OnMessages, 13497 Sends, over 279 seconds)
2022/10/13 20:16:35 copy loop ended
2022/10/13 20:16:35 datachannelHandler ends
2022/10/13 20:18:59 sdp offer successfully received.
2022/10/13 20:18:59 Generating answer...
2022/10/13 20:19:19 Timed out waiting for client to open data channel.
2022/10/13 20:25:58 sdp offer successfully received.
2022/10/13 20:25:58 Generating answer...
2022/10/13 20:26:21 Timed out waiting for client to open data channel.
2022/10/13 20:28:00 sdp offer successfully received.
2022/10/13 20:28:00 Generating answer...
2022/10/13 20:28:21 Timed out waiting for client to open data channel.
2022/10/13 20:36:58 In the last 1h0m0s, there were 5 connections. Traffic Relayed ↑ 21 MB, ↓ 2 MB.
2022/10/13 20:44:43 OnClose channel
2022/10/13 20:44:43 Traffic throughput (up|down): 47 MB|8 MB -- (20665 OnMessages, 44294 Sends, over 1770 seconds)
2022/10/13 20:44:43 copy loop ended
2022/10/13 20:44:43 datachannelHandler ends
2022/10/13 20:51:19 sdp offer successfully received.
2022/10/13 20:51:19 Generating answer...
2022/10/13 20:51:39 Timed out waiting for client to open data channel.
2022/10/13 20:55:26 sdp offer successfully received.
2022/10/13 20:55:26 Generating answer...
2022/10/13 20:55:47 Timed out waiting for client to open data channel.
2022/10/13 20:55:48 sdp offer successfully received.
2022/10/13 20:55:48 Generating answer...
2022/10/13 20:56:08 Timed out waiting for client to open data channel.
2022/10/13 20:58:18 sdp offer successfully received.
2022/10/13 20:58:18 Generating answer...
2022/10/13 20:58:38 Timed out waiting for client to open data channel.
2022/10/13 20:59:49 sdp offer successfully received.
2022/10/13 20:59:49 Generating answer...
2022/10/13 21:00:10 Timed out waiting for client to open data channel.
2022/10/13 21:02:20 sdp offer successfully received.
2022/10/13 21:02:20 Generating answer...
2022/10/13 21:02:41 Timed out waiting for client to open data channel.
2022/10/13 21:36:58 In the last 1h0m0s, there were 1 connections. Traffic Relayed ↑ 47 MB, ↓ 8 MB.
2022/10/13 21:56:52 sdp offer successfully received.
2022/10/13 21:56:52 Generating answer...
2022/10/13 21:57:12 Timed out waiting for client to open data channel.
2022/10/13 22:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/13 23:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 00:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 01:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 02:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 03:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 04:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 05:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
2022/10/14 06:36:58 In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B.
Similar to my standalone proxy (running 24/7). Now 36h’s with zero activity.
Traffic stopped between 2022/10/13 02:00:00 and 03:00:00.
Peek count in “Traffic throughput” was approx. 26850 OnMessages over 1770 seconds.
I guess it’s worth checking to see if you’re updated:
Eventually I did restart proxy and it did proxy messages as being designed for after having offered it’s service.
Again, after approx. 13h normal operation and proxying, now 12h with zero activity, no sdp offers logged.
lsof shows five external IPv6 connections on arbitrary ports in status established. Process has 9 threads established.
Mine also in les then 24 hours got 0 clients in the last 3-4 intervals.
Does anyone know how to add an auto restart function for the container?
Try here. You’ll need to look for a process manager as well:
My snowflake proxy has 5 IPv6 https connections in status established with snowflake server. If there is no traffic registered, snowflake server has either a bug on load distribution or made a decision not to use these connections? (now 15h of zero traffic relayed)
Finding: iftop presents low traffic on connection to snowflake server. So, both sides talk to each other. Two connections seem to be actively in use.
At least one host resolves to snowflake-01, the second is shown as m-dnslb-a01.
I’ll keep it running …
Update: all 5 connections terminate on snowflake-01 with little traffic (40s average: approx. 400 Bytes/s)
Now 29 repeats on stdout (nohup.out) of
In the last 1h0m0s, there were 0 connections. Traffic Relayed ↑ 0 B, ↓ 0 B
My conclusion: There’s either no demand for this (my) snowflake proxy or my proxy is ignored for some reason.
I’ll keep it running …
My containers all aready configured to autostart in case of failure/crash
i’m using ->unless-stopped option.
But the fact that there are no connections to proxy doesn’t mean the container has issues. I wanted to add a timer or something when i start the container to have the option to restart after 24h hours, at least untill the bug is solved 
Something silimar to -verbose.
Have found a new snowflake commit in git (8b1970a3ce85436e87a9ac868652c3fc3d8c4b58), cloned and compiled it.
Restarted local snowflake proxy with this version …
New message in nohup.out
Bad range port format: 0xc000222070
But it does work and relay messages. …
I made bug report about it:
Which is good news. Maybe the message means the server/broker (?) tried a port, spit out the message and then moved on. (Edit: see @Vort ’s issue #40215 above)
By the way, here’s a restart script for nohup from another user, @Beckers
use the “@reboot” directive in /etc/crontab to start a script which contains “nohup /full/path/to/proxy/ -summary-interval 30m -log /full/path/to/proxy.log”. The server is restarted every 24 hours.
Now, again, 16 zero activity messages in sequence. Still 5 TCP connections to snowflake-01 (my proxy is started with -capacity 5). No UDP traffic anymore. During first hours after restart, lsof did list plenty of UDP ports allocated. Now none anymore.
IMHO draining of snowflake proxies happens on the server side! And a proxy restart is like “new game, new luck”.