Snowflake issueshttps://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/-/issues2024-03-04T08:42:02Zhttps://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/-/issues/40340Add a mechanism to retest the client NAT type2024-03-04T08:42:02ZCecylia BocovichAdd a mechanism to retest the client NAT typeWhile we do periodically retest the NAT type of proxies, a client's NAT type is only checked once on startup. The result is that if, after the initial check, a client's network conditions change, they may have difficulty connecting to pr...While we do periodically retest the NAT type of proxies, a client's NAT type is only checked once on startup. The result is that if, after the initial check, a client's network conditions change, they may have difficulty connecting to proxies in their pool. Since client usage of snowflake is much more time-sensitive than proxies, the trigger for a retest could be a threshold of a certain number of failed Datachannel attempts.https://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/-/issues/40204pion errors don't go into the log2022-12-03T13:45:30ZRoger Dingledinepion errors don't go into the logMy snowflake proxy tells me, I guess on either stdout or stderr,
```
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0...My snowflake proxy tells me, I guess on either stdout or stderr,
```
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
sctp ERROR: 2022/10/03 13:47:32 [0xc002986380] stream 1 not found)
```
but I am using -log, and these lines don't show up in the log. It is unexpected that "error" category messages would be the ones that are transient and not captured for posterity.
(Also, the timestamps in the log seem to be utc, and the timestamps on my stdout/stderr appear to be local timezone. Not sure if that merits a separate ticket -- let me know if yes and I can open it.)Linus Nordberglinus@torproject.orgLinus Nordberglinus@torproject.orghttps://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/-/issues/40197nil pointer dereference in PeerConnection.PendingLocalDescription2022-10-03T11:53:14Zcypherpunksnil pointer dereference in PeerConnection.PendingLocalDescription```
info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on...```
info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
info] {EDGE} connection_edge_process_inbuf(): data from edge while in 'waiting for circuit' state. Leaving it on buffer.
info] {NET} parse_socks_client(): SOCKS 5 client: continuing without authentication
info] {NET} connection_read_proxy_handshake(): Proxy Client: OR connection (handshaking (proxy)) with 192.0.2.3:80 ID=1zOHpg+FxqQfi/6jDLtCpHHqBTH8gjYmCKXkus1D5Ko RSA_ID=2B280B23E1107BB62ABFC40DDCC8824814F80A72 successful
info] {BTRACK} bto_update_best(): ORCONN BEST_ANY state 2->3 gid=4
notice] {CONTROL} Bootstrapped 10% (conn_done): Connected to a relay
info] {BTRACK} bto_update_best(): ORCONN BEST_AP state 2->3 gid=4
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: panic: runtime error: invalid memory address or nil pointer dereference
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: [signal 0xc0000005 code=0x0 addr=0x0 pc=0x5ed17d]
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error:
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: goroutine 53 [running]:
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: github.com/pion/webrtc.(*PeerConnection).PendingLocalDescription(0x0)
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/github.com/pion/webrtc/peerconnection.go:2026 +0x1d
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: github.com/pion/webrtc.(*PeerConnection).LocalDescription(0xc00034c000)
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/github.com/pion/webrtc/peerconnection.go:1007 +0x1e
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib.(*WebRTCPeer).connect(0xc00034c000, 0x0, 0xc000345d48)
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib/webrtc.go:150 +0xd8
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib.NewWebRTCPeerWithEvents(0x35ee40, 0xc0000d6000, {0x223f8f30008, 0xc00022e220})
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib/webrtc.go:73 +0x38b
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib.WebRTCDialer.Catch(...)
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib/rendezvous.go:172
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib.(*Peers).Collect(0xc000234080)
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib/peers.go:69 +0x223
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib.connectLoop({0x846bd0, 0xc000234080})
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib/snowflake.go:345 +0x56
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: created by git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib.(*Transport).Dial
info] {PT} managed_proxy_stderr_callback(): Managed proxy at 'PluggableTransports\snowflake-client.exe' reported via standard error: /var/tmp/dist/gopath/src/git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib/snowflake.go:170 +0x206
info] {NET} TLS error: <syscall error while handshaking> (errno=10054: Connection reset by peer [WSAECONNRESET ]; state=SSLv3/TLS write client hello)
info] {OR} connection_tls_continue_handshake(): tls error [connection reset]. breaking connection.
info] {CIRC} circuit_n_chan_done(): Channel failed; closing circ.
info] {GENERAL} circuit_mark_for_close_(): Circuit 0 (id: 1) marked for close at circuitbuild.c:687 (orig reason: 8, new reason: 0)
info] {HANDSHAKE} connection_or_note_state_when_broken(): Connection died in state 'handshaking (TLS) with SSL state SSLv3/TLS write client hello in HANDSHAKE'
info] {BTRACK} bto_status_rcvr(): ORCONN DELETE gid=4 status=2 reason=4
warn] {CONTROL} Problem bootstrapping. Stuck at 10% (conn_done): Connected to a relay. (CONNECTRESET; CONNECTRESET; count 1; recommendation warn; host 2B280B23E1107BB62ABFC40DDCC8824814F80A72 at 192.0.2.3:80)
warn] {HANDSHAKE} 1 connections have failed:
warn] {HANDSHAKE} 1 connections died in state handshaking (TLS) with SSL state SSLv3/TLS write client hello in HANDSHAKE
info] {OR} circuit_build_failed(): Our circuit 0 (id: 1) died before the first hop with no connection
info] {GUARD} entry_guards_note_guard_failure(): Recorded failure for primary guard $2B280B23E1107BB62ABFC40DDCC8824814F80A72 ($2B280B23E1107BB62ABFC40DDCC8824814F80A72)
info] {CIRC} circuit_free_(): Circuit 0 (id: 1) has been freed.
warn] {PT} Pluggable Transport process terminated with status code 2
```