Trac issueshttps://gitlab.torproject.org/legacy/trac/-/issues2020-06-13T18:20:32Zhttps://gitlab.torproject.org/legacy/trac/-/issues/31100Firefox addon not reporting any users2020-06-13T18:20:32ZCecylia BocovichFirefox addon not reporting any usersIt's unclear to me whether the Firefox addon is working correctly. I've gotten no usage out of it and have the following messages/errors in the console:
```
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remot...It's unclear to me whether the Firefox addon is working correctly. I've gotten no usage out of it and have the following messages/errors in the console:
```
Cross-Origin Request Blocked: The Same Origin Policy disallows reading the remote resource at https://snowflake-broker.bamsoftware.com/proxy. (Reason: CORS request did not succeed).
ICE failed, add a STUN server and see about:webrtc for more details
```Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/31092Specify a location where users can report issues for the Snowflake WebExtension2020-06-13T18:20:31ZcypherpunksSpecify a location where users can report issues for the Snowflake WebExtensionand mention it in the respective addon store pagesand mention it in the respective addon store pagesCecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30999Spruce up the product pages2020-06-13T18:20:27ZArlo BreaultSpruce up the product pagesThis is going to need some screenshots and verbage and whatnot,
https://addons.mozilla.org/en-US/firefox/addon/torproject-snowflake/This is going to need some screenshots and verbage and whatnot,
https://addons.mozilla.org/en-US/firefox/addon/torproject-snowflake/Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/21315publish some realtime stats from the broker?2020-06-13T18:20:25ZRoger Dingledinepublish some realtime stats from the broker?How many snowflakes are there registered right now and happy to serve censored users?
Right now there's a big difference between 0 and 1, and it's not easy to figure out which it is.
Knowing this number would help me as a snowflake vol...How many snowflakes are there registered right now and happy to serve censored users?
Right now there's a big difference between 0 and 1, and it's not easy to figure out which it is.
Knowing this number would help me as a snowflake volunteer decide whether I am needed, and whether to do advocacy at this moment to get other people to be snowflakes.
Knowing this number would help the censored users too, because it would give them a sense of the health of the snowflake population, and also it can help them debug their "it's not working, I wonder if I can narrow down some possible problems" situations.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30934Add a "Turn Off/On" toggle2020-06-13T18:20:24ZArlo BreaultAdd a "Turn Off/On" toggleAs in the mockup in comment:5:ticket:23888
For now, the extension can be disabled from the browser's management pane, if so desired.As in the mockup in comment:5:ticket:23888
For now, the extension can be disabled from the browser's management pane, if so desired.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30878Set up snowbox to simulate censorship2020-06-13T18:20:20ZCecylia BocovichSet up snowbox to simulate censorshipWe can use the VPS in china to see how current blocking affects Tor clients. But it doesn't tell us:
- How this impacts the user experience of Tor Browser
- How future plausible censorship events will impact the experience of Tor Browse...We can use the VPS in china to see how current blocking affects Tor clients. But it doesn't tell us:
- How this impacts the user experience of Tor Browser
- How future plausible censorship events will impact the experience of Tor Browser
- How misbehaving snowflake proxies will impact the experience of Tor Browser
We should try to set up our current testing environment to do some of these things.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30867Write proxy-go tests to cover existing implementation2020-06-13T18:20:19ZCecylia BocovichWrite proxy-go tests to cover existing implementationCurrently we only have proxy-go tests to test extracting the client's remote IP from the SDP offer.
We should increase test coverage.Currently we only have proxy-go tests to test extracting the client's remote IP from the SDP offer.
We should increase test coverage.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30830Clean up snowflake broker logs2020-06-13T18:20:18ZCecylia BocovichClean up snowflake broker logsWe recently produces graphs from the unsanitized broker logs [here](https://trac.torproject.org/projects/tor/ticket/30693#comment:3). However, the script to produce these graphs was complicated due to the structure of the log messages. W...We recently produces graphs from the unsanitized broker logs [here](https://trac.torproject.org/projects/tor/ticket/30693#comment:3). However, the script to produce these graphs was complicated due to the structure of the log messages. We should evaluate log output from the broker and decide what to keep, what to change, and what to discard.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/25429Need something better than client's `checkForStaleness`2020-06-13T18:20:17ZArlo BreaultNeed something better than client's `checkForStaleness`If no message has been received on the datachannel on the client for `SnowflakeTimeout` (30 seconds), `checkForStaleness` closes the connection. The comment says this is to,
> // Prevent long-lived broken remotes.
but there's no hear...If no message has been received on the datachannel on the client for `SnowflakeTimeout` (30 seconds), `checkForStaleness` closes the connection. The comment says this is to,
> // Prevent long-lived broken remotes.
but there's no heartbeat at this level of abstraction so the connection is constantly being reset anytime the user pauses their activity (for example, to read a webpage).
This greatly exacerbated #21312Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30579Add more STUN servers to the default snowflake configuration in Tor Browser2020-06-13T18:20:08ZCecylia BocovichAdd more STUN servers to the default snowflake configuration in Tor BrowserRight now snowflake blocking in China is happening in the client's connection to the default STUN server (which is set to Google's STUN servers). We should add more STUN servers, including ones that are popular in regions that are trying...Right now snowflake blocking in China is happening in the client's connection to the default STUN server (which is set to Google's STUN servers). We should add more STUN servers, including ones that are popular in regions that are trying to block snowflake so that blocking this stage causes more collateral damage.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/25688proxy-go is still deadlocking occasionally2020-06-13T18:20:06ZDavid Fifielddcf@torproject.orgproxy-go is still deadlocking occasionallyThe three fallback proxy-go instances are still hanging, after variable delays of a few days. This is even after removing all memory restrictions I discussed in comment:64:ticket:21312.
The more heavily used instances seem to deadlock s...The three fallback proxy-go instances are still hanging, after variable delays of a few days. This is even after removing all memory restrictions I discussed in comment:64:ticket:21312.
The more heavily used instances seem to deadlock sooner. Those for the currently used broker would be more likely to stop than those for the standalone broker. But the ones for the standalone broker would stop too.
In the meantime, I've put the fallback proxies back on periodic restarts. Before the intervals were 1h,2h,10h; now I increased them to 17h,23h,29h (prime numbers, so the average time before the next restart is < 17h).
I'll update this ticket with a graph showing uptimes when I have time.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30451snowflake-client has executable stack2020-06-13T18:20:02Zboklmsnowflake-client has executable stackRunning this command shows that the `snowflake-client` binary has an executable stack:
```
$ readelf -W -l TorBrowser/Tor/PluggableTransports/snowflake-client | grep GNU_STACK
GNU_STACK 0x000000 0x0000000000000000 0x00000000000000...Running this command shows that the `snowflake-client` binary has an executable stack:
```
$ readelf -W -l TorBrowser/Tor/PluggableTransports/snowflake-client | grep GNU_STACK
GNU_STACK 0x000000 0x0000000000000000 0x0000000000000000 0x000000 0x000000 RWE 0x10
```
(RWE should be RW when the stack is not executable)Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30368Run some tests to check reachability of snowflake proxies2020-06-13T18:20:01ZCecylia BocovichRun some tests to check reachability of snowflake proxiesOur standalone proxies were recently blocked in China: #30350
We should start running some probe tests like we are for obfs4 to see whether this blocking was a one-off event and detect blocking of new proxy instances.Our standalone proxies were recently blocked in China: #30350
We should start running some probe tests like we are for obfs4 to see whether this blocking was a one-off event and detect blocking of new proxy instances.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30350Hello, in China, currently, Tor Browser 8.5a11 version can't connect to Tor n...2020-06-13T18:19:58ZTracHello, in China, currently, Tor Browser 8.5a11 version can't connect to Tor network through Snowflake bridge.Hello, in China, currently, Tor Browser 8.5a11 version can't connect to Tor network through Snowflake bridge. On this April 17th, in China, Tor Browser 8.5a11 version can connect to Tor network through Snowflake bridge. But currently, in...Hello, in China, currently, Tor Browser 8.5a11 version can't connect to Tor network through Snowflake bridge. On this April 17th, in China, Tor Browser 8.5a11 version can connect to Tor network through Snowflake bridge. But currently, in China, Tor Browser 8.5a11 version can't connect to Tor network through Snowflake bridge. Does China's firewall block all of the Snowflake bridges? " Tor failed to establish a Tor network connection. Connected to a Tor relay failed. (done - 0.0.3.0:1) " is showed in connection interface.
Below is Tor log messages.
```
5/1/19, 05:10:31.667 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
5/1/19, 05:10:37.818 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
5/1/19, 05:10:37.818 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
5/1/19, 05:10:37.818 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
5/1/19, 05:10:37.818 [NOTICE] Opening Socks listener on 127.0.0.1:9150
5/1/19, 05:10:37.818 [NOTICE] Opened Socks listener on 127.0.0.1:9150
5/1/19, 05:10:38.802 [NOTICE] Bootstrapped 1% (conn_pt): Connecting to pluggable transport
5/1/19, 05:10:38.803 [NOTICE] Bootstrapped 2% (conn_done_pt): Connected to pluggable transport
5/1/19, 05:11:21.559 [NOTICE] Bootstrapped 10% (conn_done): Connected to a relay
5/1/19, 05:11:51.686 [WARN] Problem bootstrapping. Stuck at 10% (conn_done): Connected to a relay. (DONE; DONE; count 1; recommendation warn; host 2B280B23E1107BB62ABFC40DDCC8824814F80A72 at 0.0.3.0:1)
5/1/19, 05:11:51.687 [WARN] 1 connections have failed:
5/1/19, 05:11:51.687 [WARN] 1 connections died in state handshaking (TLS) with SSL state SSLv2/v3 read server hello A in HANDSHAKE
5/1/19, 05:11:51.702 [NOTICE] Closing no-longer-configured Socks listener on 127.0.0.1:9150
5/1/19, 05:11:51.702 [NOTICE] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections.
5/1/19, 05:11:51.702 [WARN] Pluggable Transport process terminated with status code 0
```
Could you please solve this problem? Thank you very much for your help. I really appreciate it.
**Trac**:
**Username**: amiableclarity2011Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30258Snowflake proxy stops working during browsing session2020-06-13T18:19:54ZCecylia BocovichSnowflake proxy stops working during browsing sessionThis was a comment on #25688:
> I'm still not a 100% sure but each 7min or so it sure looks like the snowflake is deadlocking (or something else?) while I'm being connected and I get another one, this is very visible in my browsing exper...This was a comment on #25688:
> I'm still not a 100% sure but each 7min or so it sure looks like the snowflake is deadlocking (or something else?) while I'm being connected and I get another one, this is very visible in my browsing experience. It would be great if you could investigate this.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30206Segfault in proxy-go2020-06-13T18:19:52ZirlSegfault in proxy-goIt happened quite quickly, so here's the full output.
```
2019/04/16 [scrubbed] starting
INFO: configuration.go:174: Created Configuration at &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: configuration.go:256: Converting ...It happened quite quickly, so here's the full output.
```
2019/04/16 [scrubbed] starting
INFO: configuration.go:174: Created Configuration at &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f65bc000c60 1} 0x7f65bc000c60
INFO: peerconnection.go:436: fired OnSignalingStateChange: 1 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 1 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 1
INFO: peerconnection.go:495: fired OnConnectionStateChange: 1
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 1
INFO: peerconnection.go:459: fired OnIceCandidate: 1 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 39908 typ host generation 0 ufrag gUW/ network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 1 candidate:498995695 1 udp 2122194687 172.22.152.130 59852 typ host generation 0 ufrag gUW/ network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 1 candidate:3509792380 1 udp 1685987071 84.92.41.201 59913 typ srflx raddr 172.22.152.130 rport 59852 generation 0 ufrag gUW/ network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 1 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 34045 typ host tcptype passive generation 0 ufrag gUW/ network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 1 candidate:1396567327 1 tcp 1518214911 172.22.152.130 54255 typ host tcptype passive generation 0 ufrag gUW/ network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 1
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 1
INFO: peerconnection.go:495: fired OnConnectionStateChange: 1
INFO: peerconnection.go:527: fired OnDataChannel: 1 0x7f6584008960
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] connected to relay
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f6580000b20 2} 0x7f6580000b20
INFO: peerconnection.go:436: fired OnSignalingStateChange: 2 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 2 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 2
INFO: peerconnection.go:495: fired OnConnectionStateChange: 2
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 2
INFO: peerconnection.go:459: fired OnIceCandidate: 2 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 59602 typ host generation 0 ufrag ZK+V network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 2 candidate:498995695 1 udp 2122194687 172.22.152.130 58452 typ host generation 0 ufrag ZK+V network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 2 candidate:3509792380 1 udp 1685987071 84.92.41.201 59538 typ srflx raddr 172.22.152.130 rport 58452 generation 0 ufrag ZK+V network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 2 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 33335 typ host tcptype passive generation 0 ufrag ZK+V network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 2 candidate:1396567327 1 tcp 1518214911 172.22.152.130 55661 typ host tcptype passive generation 0 ufrag ZK+V network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 2
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 2
INFO: peerconnection.go:495: fired OnConnectionStateChange: 2
INFO: peerconnection.go:527: fired OnDataChannel: 2 0x7f656800a310
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] connected to relay
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f658c000b20 3} 0x7f658c000b20
INFO: peerconnection.go:436: fired OnSignalingStateChange: 3 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 3 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 3
INFO: peerconnection.go:495: fired OnConnectionStateChange: 3
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 3
INFO: peerconnection.go:459: fired OnIceCandidate: 3 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 36827 typ host generation 0 ufrag Ixjw network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 3 candidate:498995695 1 udp 2122194687 172.22.152.130 47070 typ host generation 0 ufrag Ixjw network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 3 candidate:3509792380 1 udp 1685987071 84.92.41.201 62688 typ srflx raddr 172.22.152.130 rport 47070 generation 0 ufrag Ixjw network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 3 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 56747 typ host tcptype passive generation 0 ufrag Ixjw network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 3 candidate:1396567327 1 tcp 1518214911 172.22.152.130 42273 typ host tcptype passive generation 0 ufrag Ixjw network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 3
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 3
INFO: peerconnection.go:495: fired OnConnectionStateChange: 3
INFO: peerconnection.go:527: fired OnDataChannel: 3 0x7f6550001130
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] connected to relay
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f658c064d20 4} 0x7f658c064d20
INFO: peerconnection.go:436: fired OnSignalingStateChange: 4 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 4 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 4
INFO: peerconnection.go:495: fired OnConnectionStateChange: 4
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 4
INFO: peerconnection.go:459: fired OnIceCandidate: 4 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 34485 typ host generation 0 ufrag TTEP network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 4 candidate:498995695 1 udp 2122194687 172.22.152.130 45068 typ host generation 0 ufrag TTEP network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 4 candidate:3509792380 1 udp 1685987071 84.92.41.201 51346 typ srflx raddr 172.22.152.130 rport 45068 generation 0 ufrag TTEP network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 4 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 47037 typ host tcptype passive generation 0 ufrag TTEP network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 4 candidate:1396567327 1 tcp 1518214911 172.22.152.130 41629 typ host tcptype passive generation 0 ufrag TTEP network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 4
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 4
INFO: peerconnection.go:495: fired OnConnectionStateChange: 4
INFO: peerconnection.go:527: fired OnDataChannel: 4 0x7f654000ad40
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] connected to relay
2019/04/16 [scrubbed] OnClose channel
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 1
INFO: peerconnection.go:436: fired OnSignalingStateChange: 1 Closed
2019/04/16 [scrubbed] datachannelHandler ends
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f6580064f40 5} 0x7f6580064f40
INFO: peerconnection.go:436: fired OnSignalingStateChange: 5 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 5 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 5
INFO: peerconnection.go:495: fired OnConnectionStateChange: 5
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 5
INFO: peerconnection.go:459: fired OnIceCandidate: 5 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 35400 typ host generation 0 ufrag qYdh network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 5 candidate:498995695 1 udp 2122194687 172.22.152.130 39835 typ host generation 0 ufrag qYdh network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 5 candidate:3509792380 1 udp 1685987071 84.92.41.201 63045 typ srflx raddr 172.22.152.130 rport 39835 generation 0 ufrag qYdh network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 5 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 55769 typ host tcptype passive generation 0 ufrag qYdh network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 5 candidate:1396567327 1 tcp 1518214911 172.22.152.130 55571 typ host tcptype passive generation 0 ufrag qYdh network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 5
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 5
INFO: peerconnection.go:495: fired OnConnectionStateChange: 5
INFO: peerconnection.go:527: fired OnDataChannel: 5 0x7f658400af30
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] connected to relay
2019/04/16 [scrubbed] OnClose channel
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 2
INFO: peerconnection.go:436: fired OnSignalingStateChange: 2 Closed
2019/04/16 [scrubbed] datachannelHandler ends
2019/04/16 [scrubbed] OnClose channel
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 3
INFO: peerconnection.go:436: fired OnSignalingStateChange: 3 Closed
2019/04/16 [scrubbed] datachannelHandler ends
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f6580061920 6} 0x7f6580061920
INFO: peerconnection.go:436: fired OnSignalingStateChange: 6 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 6 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 6
INFO: peerconnection.go:495: fired OnConnectionStateChange: 6
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 6
INFO: peerconnection.go:459: fired OnIceCandidate: 6 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 59583 typ host generation 0 ufrag eVKt network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 6 candidate:498995695 1 udp 2122194687 172.22.152.130 47513 typ host generation 0 ufrag eVKt network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 6 candidate:3509792380 1 udp 1685987071 84.92.41.201 50031 typ srflx raddr 172.22.152.130 rport 47513 generation 0 ufrag eVKt network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 6 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 59003 typ host tcptype passive generation 0 ufrag eVKt network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 6 candidate:1396567327 1 tcp 1518214911 172.22.152.130 49119 typ host tcptype passive generation 0 ufrag eVKt network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 6
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 6
INFO: peerconnection.go:495: fired OnConnectionStateChange: 6
INFO: peerconnection.go:527: fired OnDataChannel: 6 0x7f655000adf0
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] connected to relay
INFO: configuration.go:256: Converting Config: &{[{[stun:stun.l.google.com:19302] }] All Balanced }
INFO: peerconnection.go:168: Created PeerConnection: &{<nil> <nil> false <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> <nil> {[{[stun:stun.l.google.com:19302] }] 3 0 } 0x7f6580000b20 7} 0x7f6580000b20
INFO: peerconnection.go:436: fired OnSignalingStateChange: 7 HaveRemoteOffer
2019/04/16 [scrubbed] sdp offer successfully received.
2019/04/16 [scrubbed] Generating answer...
INFO: peerconnection.go:436: fired OnSignalingStateChange: 7 Stable
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 7
INFO: peerconnection.go:495: fired OnConnectionStateChange: 7
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 7
INFO: peerconnection.go:459: fired OnIceCandidate: 7 candidate:1020330603 1 udp 2122262783 2001:470:1d58:1337:2066:3507:9c2e:9cc8 50955 typ host generation 0 ufrag cbJC network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 7 candidate:498995695 1 udp 2122194687 172.22.152.130 39725 typ host generation 0 ufrag cbJC network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 7 candidate:3509792380 1 udp 1685987071 84.92.41.201 60984 typ srflx raddr 172.22.152.130 rport 39725 generation 0 ufrag cbJC network-id 1 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 7 candidate:1918041755 1 tcp 1518283007 2001:470:1d58:1337:2066:3507:9c2e:9cc8 49269 typ host tcptype passive generation 0 ufrag cbJC network-id 2 network-cost 50
INFO: peerconnection.go:459: fired OnIceCandidate: 7 candidate:1396567327 1 tcp 1518214911 172.22.152.130 35571 typ host tcptype passive generation 0 ufrag cbJC network-id 1 network-cost 50
INFO: peerconnection.go:513: fired OnIceGatheringStateChange: 7
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 7
INFO: peerconnection.go:495: fired OnConnectionStateChange: 7
INFO: peerconnection.go:527: fired OnDataChannel: 7 0x7f6544008100
2019/04/16 [scrubbed] OnDataChannel
2019/04/16 [scrubbed] OnOpen channel
2019/04/16 [scrubbed] OnMessage <--- 200 bytes
2019/04/16 [scrubbed] connected to relay
2019/04/16 [scrubbed] Write 754 bytes --> WebRTC
2019/04/16 [scrubbed] OnMessage <--- 126 bytes
2019/04/16 [scrubbed] Write 51 bytes --> WebRTC
2019/04/16 [scrubbed] OnMessage <--- 40 bytes
2019/04/16 [scrubbed] Write 1524 bytes --> WebRTC
2019/04/16 [scrubbed] OnMessage <--- 1057 bytes
2019/04/16 [scrubbed] Write 543 bytes --> WebRTC
2019/04/16 [scrubbed] OnClose channel
INFO: peerconnection.go:504: fired OnIceConnectionStateChange: 4
INFO: peerconnection.go:436: fired OnSignalingStateChange: 4 Closed
2019/04/16 [scrubbed] datachannelHandler ends
2019/04/16 [scrubbed] broker returns: 504
fatal error: unexpected signal during runtime execution
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x66a11a]
runtime stack:
runtime.throw(0xeea8ff, 0x2a)
/usr/lib/go-1.11/src/runtime/panic.go:608 +0x72
runtime.sigpanic()
/usr/lib/go-1.11/src/runtime/signal_unix.go:374 +0x2f2
goroutine 43 [syscall]:
runtime.cgocall(0x668210, 0xc000249748, 0xc0004c8300)
/usr/lib/go-1.11/src/runtime/cgocall.go:128 +0x5e fp=0xc000249718 sp=0xc0002496e0 pc=0x41c51e
github.com/keroserene/go-webrtc._Cfunc_CGO_IceConnectionState(0x7f65bc000c60, 0x7f6500000000)
_cgo_gotypes.go:555 +0x49 fp=0xc000249748 sp=0xc000249718 pc=0x6578f9
github.com/keroserene/go-webrtc.(*PeerConnection).ConnectionState.func1(0x7f65bc000c60, 0xc000270101)
/home/irl/go/src/github.com/keroserene/go-webrtc/peerconnection.go:286 +0x56 fp=0xc000249780 sp=0xc000249748 pc=0x65cd26
github.com/keroserene/go-webrtc.(*PeerConnection).ConnectionState(0xc0000d62c0, 0x0)
/home/irl/go/src/github.com/keroserene/go-webrtc/peerconnection.go:286 +0x32 fp=0xc0002497a0 sp=0xc000249780 pc=0x65aba2
main.makePeerConnectionFromOffer.func3(0xc0000d62c0)
/tmp/snowflake/proxy-go/snowflake.go:339 +0x59 fp=0xc0002497d8 sp=0xc0002497a0 pc=0x667179
runtime.goexit()
/usr/lib/go-1.11/src/runtime/asm_amd64.s:1333 +0x1 fp=0xc0002497e0 sp=0xc0002497d8 pc=0x46ff51
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 1 [select]:
net/http.(*http2ClientConn).roundTrip(0xc000346c40, 0xc0004c0000, 0x0, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:7665 +0x7cc
net/http.(*http2Transport).RoundTripOpt(0xc0000aa410, 0xc0004c0000, 0x0, 0x30000c0002c212b, 0x42ac1c, 0xedebef)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:7037 +0x153
net/http.(*http2Transport).RoundTrip(0xc0000aa410, 0xc0004c0000, 0xc0004d6240, 0x128e310, 0x0)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:6999 +0x3a
net/http.http2noDialH2RoundTripper.RoundTrip(0xc0000aa410, 0xc0004c0000, 0xc0004ce540, 0x5, 0xc0000c1168)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:1019 +0x39
net/http.(*Transport).roundTrip(0x128e380, 0xc0004c0000, 0x203000, 0xc000129a30, 0x5fd22d)
/usr/lib/go-1.11/src/net/http/transport.go:415 +0xd4c
net/http.(*Transport).RoundTrip(0x128e380, 0xc0004c0000, 0x128e380, 0x0, 0x0)
/usr/lib/go-1.11/src/net/http/roundtrip.go:17 +0x35
net/http.send(0xc0004c0000, 0xf27f60, 0x128e380, 0x0, 0x0, 0x0, 0xc00000e040, 0x7f65e649b440, 0xc000129ac0, 0x1)
/usr/lib/go-1.11/src/net/http/client.go:250 +0x14b
net/http.(*Client).send(0x12c01a0, 0xc0004c0000, 0x0, 0x0, 0x0, 0xc00000e040, 0x0, 0x1, 0xc0001eb500)
/usr/lib/go-1.11/src/net/http/client.go:174 +0xfa
net/http.(*Client).do(0x12c01a0, 0xc0004c0000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/http/client.go:641 +0x2a8
net/http.(*Client).Do(0x12c01a0, 0xc0004c0000, 0xc, 0xc000374280, 0x16)
/usr/lib/go-1.11/src/net/http/client.go:509 +0x35
main.pollOffer(0xc000374280, 0x16, 0x0)
/tmp/snowflake/proxy-go/snowflake.go:157 +0x37f
main.runSession(0xc000374280, 0x16)
/tmp/snowflake/proxy-go/snowflake.go:351 +0x39
main.main()
/tmp/snowflake/proxy-go/snowflake.go:423 +0x5ba
goroutine 80 [semacquire]:
sync.runtime_Semacquire(0xc0002dd768)
/usr/lib/go-1.11/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc0002dd760)
/usr/lib/go-1.11/src/sync/waitgroup.go:130 +0x64
main.CopyLoopTimeout(0xf2b6e0, 0xc0001ad2f0, 0xf2b680, 0xc0001743f0, 0xdf8475800)
/tmp/snowflake/proxy-go/snowflake.go:223 +0x253
main.datachannelHandler(0xc0001ad2f0, 0xf29660, 0xc0001ad380)
/tmp/snowflake/proxy-go/snowflake.go:258 +0x383
created by main.makePeerConnectionFromOffer.func2
/tmp/snowflake/proxy-go/snowflake.go:303 +0x2ac
goroutine 12 [IO wait]:
internal/poll.runtime_pollWait(0x7f65e1a49f00, 0x72, 0xc000231870)
/usr/lib/go-1.11/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc0001d6098, 0x72, 0xffffffffffffff00, 0xf28a00, 0x12940d0)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc0001d6098, 0xc0001f6000, 0x1000, 0x1000)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc0001d6080, 0xc0001f6000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/internal/poll/fd_unix.go:169 +0x179
net.(*netFD).Read(0xc0001d6080, 0xc0001f6000, 0x1000, 0x1000, 0x421cdb, 0x1290d00, 0xe943e0)
/usr/lib/go-1.11/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0001bc010, 0xc0001f6000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/net.go:177 +0x68
crypto/tls.(*block).readFromUntil(0xc0001ac1e0, 0xf27f00, 0xc0001bc010, 0x5, 0xc0001bc010, 0x0)
/usr/lib/go-1.11/src/crypto/tls/conn.go:492 +0x89
crypto/tls.(*Conn).readRecord(0xc0001ea000, 0xef3617, 0xc0001ea120, 0x0)
/usr/lib/go-1.11/src/crypto/tls/conn.go:593 +0xdd
crypto/tls.(*Conn).Read(0xc0001ea000, 0xc00016b000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/crypto/tls/conn.go:1145 +0xf1
bufio.(*Reader).Read(0xc0001b4ba0, 0xc0005443b8, 0x9, 0x9, 0x100000000000009, 0x0, 0x10)
/usr/lib/go-1.11/src/bufio/bufio.go:216 +0x22f
io.ReadAtLeast(0xf27ba0, 0xc0001b4ba0, 0xc0005443b8, 0x9, 0x9, 0x9, 0xc0004d6180, 0x10, 0xeb7a40)
/usr/lib/go-1.11/src/io/io.go:310 +0x88
io.ReadFull(0xf27ba0, 0xc0001b4ba0, 0xc0005443b8, 0x9, 0x9, 0xf4b1a374b92e2501, 0x3, 0xc000024570)
/usr/lib/go-1.11/src/io/io.go:329 +0x58
net/http.http2readFrameHeader(0xc0005443b8, 0x9, 0x9, 0xf27ba0, 0xc0001b4ba0, 0x0, 0x0, 0xc00026f3a0, 0xc000231db8)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:1545 +0x7b
net/http.(*http2Framer).ReadFrame(0xc000544380, 0xc00026f3a0, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:1803 +0xa3
net/http.(*http2clientConnReadLoop).run(0xc000231fb8, 0xef3098, 0xc00048b7b8)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:8263 +0x9e
net/http.(*http2ClientConn).readLoop(0xc000346c40)
/usr/lib/go-1.11/src/net/http/h2_bundle.go:8191 +0x76
created by net/http.(*http2Transport).newClientConn
/usr/lib/go-1.11/src/net/http/h2_bundle.go:7264 +0x636
goroutine 81 [IO wait]:
internal/poll.runtime_pollWait(0x7f65e1a49e30, 0x72, 0xc00022c8d0)
/usr/lib/go-1.11/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc000020d98, 0x72, 0xffffffffffffff00, 0xf28a00, 0x12940d0)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc000020d98, 0xc000525400, 0x400, 0x400)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc000020d80, 0xc000525400, 0x400, 0x400, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/internal/poll/fd_unix.go:169 +0x179
net.(*netFD).Read(0xc000020d80, 0xc000525400, 0x400, 0x400, 0x421cdb, 0x1290d00, 0xe943e0)
/usr/lib/go-1.11/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e188, 0xc000525400, 0x400, 0x400, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/net.go:177 +0x68
crypto/tls.(*block).readFromUntil(0xc0001ad440, 0xf27f00, 0xc00000e188, 0x5, 0xc00000e188, 0x3)
/usr/lib/go-1.11/src/crypto/tls/conn.go:492 +0x89
crypto/tls.(*Conn).readRecord(0xc0004ae380, 0xef3617, 0xc0004ae4a0, 0x40)
/usr/lib/go-1.11/src/crypto/tls/conn.go:593 +0xdd
crypto/tls.(*Conn).Read(0xc0004ae380, 0xc000415000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/crypto/tls/conn.go:1145 +0xf1
bufio.(*Reader).fill(0xc000076ea0)
/usr/lib/go-1.11/src/bufio/bufio.go:100 +0x10f
bufio.(*Reader).ReadByte(0xc000076ea0, 0xc0000ab3b0, 0x49c332, 0xc000020d80)
/usr/lib/go-1.11/src/bufio/bufio.go:242 +0x39
golang.org/x/net/websocket.hybiFrameReaderFactory.NewFrameReader(0xc000076ea0, 0xef3600, 0xc000174418, 0xbf25b0e43acddb06, 0x170eb2420c)
/home/irl/go/src/golang.org/x/net/websocket/hybi.go:123 +0x60
golang.org/x/net/websocket.(*Conn).Read(0xc0001743f0, 0xc00060e000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
/home/irl/go/src/golang.org/x/net/websocket/websocket.go:197 +0x1b1
main.timeoutConn.Read(0xf2b680, 0xc0001743f0, 0xdf8475800, 0xc00060e000, 0x8000, 0x8000, 0xe78f60, 0x1, 0xc00060e000)
/tmp/snowflake/proxy-go/snowflake.go:198 +0x99
io.copyBuffer(0x7f65e1a4a518, 0xc0002c46a0, 0x7f65e1a4a538, 0xc0002c46c0, 0xc00060e000, 0x8000, 0x8000, 0xeb7080, 0x0, 0x7f65e1a4a538)
/usr/lib/go-1.11/src/io/io.go:402 +0x125
io.Copy(0x7f65e1a4a518, 0xc0002c46a0, 0x7f65e1a4a538, 0xc0002c46c0, 0xc0002c46c0, 0xc000118300, 0x5348fe)
/usr/lib/go-1.11/src/io/io.go:364 +0x5a
main.CopyLoopTimeout.func1(0xf2a660, 0xc0002c46a0, 0xf2a660, 0xc0002c46c0)
/tmp/snowflake/proxy-go/snowflake.go:216 +0xd2
created by main.CopyLoopTimeout
/tmp/snowflake/proxy-go/snowflake.go:221 +0x16d
goroutine 71 [chan receive]:
main.makePeerConnectionFromOffer.func3(0xc0000d6580)
/tmp/snowflake/proxy-go/snowflake.go:338 +0x4b
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 78 [chan receive]:
main.makePeerConnectionFromOffer.func3(0xc0000d66e0)
/tmp/snowflake/proxy-go/snowflake.go:338 +0x4b
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 69 [chan receive]:
main.makePeerConnectionFromOffer.func3(0xc0000d6370)
/tmp/snowflake/proxy-go/snowflake.go:338 +0x4b
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 105 [select]:
io.(*pipe).Read(0xc0000aa140, 0xc0000b0000, 0x8000, 0x8000, 0x1b, 0x1b, 0xc000374660)
/usr/lib/go-1.11/src/io/pipe.go:50 +0xea
io.(*PipeReader).Read(0xc000206000, 0xc0000b0000, 0x8000, 0x8000, 0x0, 0xf27d80, 0xc0002ec240)
/usr/lib/go-1.11/src/io/pipe.go:127 +0x4c
main.(*webRTCConn).Read(0xc0001ac000, 0xc0000b0000, 0x8000, 0x8000, 0xf27d80, 0xc0002ec240, 0x12c0400)
/tmp/snowflake/proxy-go/snowflake.go:77 +0x4d
main.timeoutConn.Read(0xf2b6e0, 0xc0001ac000, 0xdf8475800, 0xc0000b0000, 0x8000, 0x8000, 0x421, 0x0, 0x0)
/tmp/snowflake/proxy-go/snowflake.go:198 +0x99
io.copyBuffer(0x7f65e1a4a518, 0xc0002d2060, 0x7f65e1a4a538, 0xc0002d2080, 0xc0000b0000, 0x8000, 0x8000, 0xeb7080, 0xc000576200, 0x7f65e1a4a538)
/usr/lib/go-1.11/src/io/io.go:402 +0x125
io.Copy(0x7f65e1a4a518, 0xc0002d2060, 0x7f65e1a4a538, 0xc0002d2080, 0xc0002d2080, 0x0, 0x0)
/usr/lib/go-1.11/src/io/io.go:364 +0x5a
main.CopyLoopTimeout.func1(0xf2a660, 0xc0002d2060, 0xf2a660, 0xc0002d2080)
/tmp/snowflake/proxy-go/snowflake.go:216 +0xd2
created by main.CopyLoopTimeout
/tmp/snowflake/proxy-go/snowflake.go:222 +0x245
goroutine 102 [chan receive]:
main.makePeerConnectionFromOffer.func3(0xc00040e0b0)
/tmp/snowflake/proxy-go/snowflake.go:338 +0x4b
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 117 [semacquire]:
sync.runtime_Semacquire(0xc00026e678)
/usr/lib/go-1.11/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc00026e670)
/usr/lib/go-1.11/src/sync/waitgroup.go:130 +0x64
main.CopyLoopTimeout(0xf2b6e0, 0xc0003ff8f0, 0xf2b680, 0xc0002a8630, 0xdf8475800)
/tmp/snowflake/proxy-go/snowflake.go:223 +0x253
main.datachannelHandler(0xc0003ff8f0, 0xf29660, 0xc0003ff980)
/tmp/snowflake/proxy-go/snowflake.go:258 +0x383
created by main.makePeerConnectionFromOffer.func2
/tmp/snowflake/proxy-go/snowflake.go:303 +0x2ac
goroutine 82 [select]:
io.(*pipe).Read(0xc0000aaa00, 0xc000606000, 0x8000, 0x8000, 0x1b, 0x1b, 0xc000357480)
/usr/lib/go-1.11/src/io/pipe.go:50 +0xea
io.(*PipeReader).Read(0xc00000e178, 0xc000606000, 0x8000, 0x8000, 0x0, 0xf27d80, 0xc0003175e0)
/usr/lib/go-1.11/src/io/pipe.go:127 +0x4c
main.(*webRTCConn).Read(0xc0001ad2f0, 0xc000606000, 0x8000, 0x8000, 0xf27d80, 0xc0003175e0, 0x12c0400)
/tmp/snowflake/proxy-go/snowflake.go:77 +0x4d
main.timeoutConn.Read(0xf2b6e0, 0xc0001ad2f0, 0xdf8475800, 0xc000606000, 0x8000, 0x8000, 0xe78f60, 0x1, 0xc000606000)
/tmp/snowflake/proxy-go/snowflake.go:198 +0x99
io.copyBuffer(0x7f65e1a4a518, 0xc0002c46e0, 0x7f65e1a4a538, 0xc0002c4700, 0xc000606000, 0x8000, 0x8000, 0xeb7080, 0x0, 0x7f65e1a4a538)
/usr/lib/go-1.11/src/io/io.go:402 +0x125
io.Copy(0x7f65e1a4a518, 0xc0002c46e0, 0x7f65e1a4a538, 0xc0002c4700, 0xc0002c4700, 0x0, 0x0)
/usr/lib/go-1.11/src/io/io.go:364 +0x5a
main.CopyLoopTimeout.func1(0xf2a660, 0xc0002c46e0, 0xf2a660, 0xc0002c4700)
/tmp/snowflake/proxy-go/snowflake.go:216 +0xd2
created by main.CopyLoopTimeout
/tmp/snowflake/proxy-go/snowflake.go:222 +0x245
goroutine 100 [chan receive]:
main.makePeerConnectionFromOffer.func3(0xc00040e210)
/tmp/snowflake/proxy-go/snowflake.go:338 +0x4b
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 104 [IO wait]:
internal/poll.runtime_pollWait(0x7f65e1a49d60, 0x72, 0xc00054b8d0)
/usr/lib/go-1.11/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc000020498, 0x72, 0xffffffffffffff00, 0xf28a00, 0x12940d0)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc000020498, 0xc0002e6000, 0x800, 0x800)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc000020480, 0xc0002e6000, 0x800, 0x800, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/internal/poll/fd_unix.go:169 +0x179
net.(*netFD).Read(0xc000020480, 0xc0002e6000, 0x800, 0x800, 0x421cdb, 0x1290d00, 0xe943e0)
/usr/lib/go-1.11/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0001dc048, 0xc0002e6000, 0x800, 0x800, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/net.go:177 +0x68
crypto/tls.(*block).readFromUntil(0xc0000995f0, 0xf27f00, 0xc0001dc048, 0x5, 0xc0001dc048, 0x424d4f)
/usr/lib/go-1.11/src/crypto/tls/conn.go:492 +0x89
crypto/tls.(*Conn).readRecord(0xc0001eb880, 0xef3617, 0xc0001eb9a0, 0x40)
/usr/lib/go-1.11/src/crypto/tls/conn.go:593 +0xdd
crypto/tls.(*Conn).Read(0xc0001eb880, 0xc0004cc000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/crypto/tls/conn.go:1145 +0xf1
bufio.(*Reader).fill(0xc0001b4540)
/usr/lib/go-1.11/src/bufio/bufio.go:100 +0x10f
bufio.(*Reader).ReadByte(0xc0001b4540, 0xc00053a0f0, 0x49c332, 0xc000020480)
/usr/lib/go-1.11/src/bufio/bufio.go:242 +0x39
golang.org/x/net/websocket.hybiFrameReaderFactory.NewFrameReader(0xc0001b4540, 0x0, 0x0, 0x8001, 0x0)
/home/irl/go/src/golang.org/x/net/websocket/hybi.go:123 +0x60
golang.org/x/net/websocket.(*Conn).Read(0xc000174120, 0xc000232000, 0x8000, 0x8000, 0x0, 0xf27d80, 0xc000010050)
/home/irl/go/src/golang.org/x/net/websocket/websocket.go:197 +0x1b1
main.timeoutConn.Read(0xf2b680, 0xc000174120, 0xdf8475800, 0xc000232000, 0x8000, 0x8000, 0x21f, 0x0, 0x0)
/tmp/snowflake/proxy-go/snowflake.go:198 +0x99
io.copyBuffer(0x7f65e1a4a518, 0xc0002d2020, 0x7f65e1a4a538, 0xc0002d2040, 0xc000232000, 0x8000, 0x8000, 0xeb7080, 0x0, 0x7f65e1a4a538)
/usr/lib/go-1.11/src/io/io.go:402 +0x125
io.Copy(0x7f65e1a4a518, 0xc0002d2020, 0x7f65e1a4a538, 0xc0002d2040, 0xc0002d2040, 0xc0002ec190, 0x5348fe)
/usr/lib/go-1.11/src/io/io.go:364 +0x5a
main.CopyLoopTimeout.func1(0xf2a660, 0xc0002d2020, 0xf2a660, 0xc0002d2040)
/tmp/snowflake/proxy-go/snowflake.go:216 +0xd2
created by main.CopyLoopTimeout
/tmp/snowflake/proxy-go/snowflake.go:221 +0x16d
goroutine 49 [chan receive]:
main.makePeerConnectionFromOffer.func3(0xc00040e000)
/tmp/snowflake/proxy-go/snowflake.go:338 +0x4b
created by main.makePeerConnectionFromOffer
/tmp/snowflake/proxy-go/snowflake.go:337 +0x35d
goroutine 118 [IO wait]:
internal/poll.runtime_pollWait(0x7f65e1a49c90, 0x72, 0xc00022a8d0)
/usr/lib/go-1.11/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc000197498, 0x72, 0xffffffffffffff00, 0xf28a00, 0x12940d0)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc000197498, 0xc0001d3800, 0x400, 0x400)
/usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc000197480, 0xc0001d3800, 0x400, 0x400, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/internal/poll/fd_unix.go:169 +0x179
net.(*netFD).Read(0xc000197480, 0xc0001d3800, 0x400, 0x400, 0x421cdb, 0x1290d00, 0xe943e0)
/usr/lib/go-1.11/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc0001bc120, 0xc0001d3800, 0x400, 0x400, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/net/net.go:177 +0x68
crypto/tls.(*block).readFromUntil(0xc0003ffa40, 0xf27f00, 0xc0001bc120, 0x5, 0xc0001bc120, 0xc0001db301)
/usr/lib/go-1.11/src/crypto/tls/conn.go:492 +0x89
crypto/tls.(*Conn).readRecord(0xc0004c6a80, 0xef3617, 0xc0004c6ba0, 0x40)
/usr/lib/go-1.11/src/crypto/tls/conn.go:593 +0xdd
crypto/tls.(*Conn).Read(0xc0004c6a80, 0xc00061e000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
/usr/lib/go-1.11/src/crypto/tls/conn.go:1145 +0xf1
bufio.(*Reader).fill(0xc0001e6cc0)
/usr/lib/go-1.11/src/bufio/bufio.go:100 +0x10f
bufio.(*Reader).ReadByte(0xc0001e6cc0, 0xc0001dbe00, 0x49c332, 0xc000197480)
/usr/lib/go-1.11/src/bufio/bufio.go:242 +0x39
golang.org/x/net/websocket.hybiFrameReaderFactory.NewFrameReader(0xc0001e6cc0, 0xef3600, 0xc0002a8658, 0xbf25b0e6dd49b702, 0x1980d4cc08)
/home/irl/go/src/golang.org/x/net/websocket/hybi.go:123 +0x60
golang.org/x/net/websocket.(*Conn).Read(0xc0002a8630, 0xc000628000, 0x8000, 0x8000, 0x0, 0x0, 0x0)
/home/irl/go/src/golang.org/x/net/websocket/websocket.go:197 +0x1b1
main.timeoutConn.Read(0xf2b680, 0xc0002a8630, 0xdf8475800, 0xc000628000, 0x8000, 0x8000, 0xe78f60, 0x1, 0xc000628000)
/tmp/snowflake/proxy-go/snowflake.go:198 +0x99
io.copyBuffer(0x7f65e1a4a518, 0xc0002d3dc0, 0x7f65e1a4a538, 0xc0002d3de0, 0xc000628000, 0x8000, 0x8000, 0xeb7080, 0x0, 0x7f65e1a4a538)
/usr/lib/go-1.11/src/io/io.go:402 +0x125
io.Copy(0x7f65e1a4a518, 0xc0002d3dc0, 0x7f65e1a4a538, 0xc0002d3de0, 0xc0002d3de0, 0x0, 0x0)
/usr/lib/go-1.11/src/io/io.go:364 +0x5a
main.CopyLoopTimeout.func1(0xf2a660, 0xc0002d3dc0, 0xf2a660, 0xc0002d3de0)
/tmp/snowflake/proxy-go/snowflake.go:216 +0xd2
created by main.CopyLoopTimeout
/tmp/snowflake/proxy-go/snowflake.go:221 +0x16d
goroutine 119 [select]:
io.(*pipe).Read(0xc0001db450, 0xc000620000, 0x8000, 0x8000, 0x1b, 0x1b, 0xc000312600)
/usr/lib/go-1.11/src/io/pipe.go:50 +0xea
io.(*PipeReader).Read(0xc0001bc110, 0xc000620000, 0x8000, 0x8000, 0x0, 0xf27d80, 0xc0002b6390)
/usr/lib/go-1.11/src/io/pipe.go:127 +0x4c
main.(*webRTCConn).Read(0xc0003ff8f0, 0xc000620000, 0x8000, 0x8000, 0xf27d80, 0xc0002b6390, 0x12c0400)
/tmp/snowflake/proxy-go/snowflake.go:77 +0x4d
main.timeoutConn.Read(0xf2b6e0, 0xc0003ff8f0, 0xdf8475800, 0xc000620000, 0x8000, 0x8000, 0xe78f60, 0x1, 0xc000620000)
/tmp/snowflake/proxy-go/snowflake.go:198 +0x99
io.copyBuffer(0x7f65e1a4a518, 0xc0002d3e00, 0x7f65e1a4a538, 0xc0002d3e20, 0xc000620000, 0x8000, 0x8000, 0xeb7080, 0xc0000d4e00, 0x7f65e1a4a538)
/usr/lib/go-1.11/src/io/io.go:402 +0x125
io.Copy(0x7f65e1a4a518, 0xc0002d3e00, 0x7f65e1a4a538, 0xc0002d3e20, 0xc0002d3e20, 0x3, 0x1)
/usr/lib/go-1.11/src/io/io.go:364 +0x5a
main.CopyLoopTimeout.func1(0xf2a660, 0xc0002d3e00, 0xf2a660, 0xc0002d3e20)
/tmp/snowflake/proxy-go/snowflake.go:216 +0xd2
created by main.CopyLoopTimeout
/tmp/snowflake/proxy-go/snowflake.go:222 +0x245
goroutine 30 [semacquire]:
sync.runtime_Semacquire(0xc00026f108)
/usr/lib/go-1.11/src/runtime/sema.go:56 +0x39
sync.(*WaitGroup).Wait(0xc00026f100)
/usr/lib/go-1.11/src/sync/waitgroup.go:130 +0x64
main.CopyLoopTimeout(0xf2b6e0, 0xc0001ac000, 0xf2b680, 0xc000174120, 0xdf8475800)
/tmp/snowflake/proxy-go/snowflake.go:223 +0x253
main.datachannelHandler(0xc0001ac000, 0xf29660, 0xc0001ac0c0)
/tmp/snowflake/proxy-go/snowflake.go:258 +0x383
created by main.makePeerConnectionFromOffer.func2
/tmp/snowflake/proxy-go/snowflake.go:303 +0x2ac
```
The second time I've run it it seems to be doing lots of WebRTC onmessage and write, which is guess is the correct operation.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30205After log sanitization, proxy-go didn't restart, broker isn't logging2020-06-13T18:19:49ZcypherpunksAfter log sanitization, proxy-go didn't restart, broker isn't loggingCecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/21304Sanitize snowflake.log2020-06-13T18:19:48ZArlo BreaultSanitize snowflake.logFor starters, the timestamps are in the local timezone. We can make that UTC
See also #19026
Known problems:
* The client logs full SDP stanzas, which include local IP addresses.
* When the websocket server panics (as in #29125), it...For starters, the timestamps are in the local timezone. We can make that UTC
See also #19026
Known problems:
* The client logs full SDP stanzas, which include local IP addresses.
* When the websocket server panics (as in #29125), it writes the client IP address to the log:
{{{
2019/01/18 18:56:29 http2: panic serving X.X.X.X:YYYY: interface conversion: *http2.responseWriter is not http.Hijacker: missing method Hijack
}}}
* The websocket server logs an IP address on certain connection errors. (These are probably automated scanners, but still...)
{{{
2019/04/01 07:02:50 http: TLS handshake error from X.X.X.X:YYYY: acme/autocert: missing server name
2019/04/01 07:53:03 http: TLS handshake error from X.X.X.X:YYYY: tls: oversized record received with length 21536
}}}
* The broker logs the raw bytes of ICE answers:
{{{
2019/03/22 06:28:32 Received answer: [XXX XXX XXX XXX ... XXX]
}}}Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/30125Port server's log sanitization to client, broker, and proxy-go2020-06-13T18:19:48ZDavid Fifielddcf@torproject.orgPort server's log sanitization to client, broker, and proxy-go#21304 added a log sanitizer to the server (bridge) code that searches for IP addresses in logs and elides them. We noted in comment:17:ticket:21304 that the other components--client, broker, and proxy-go--can benefit from the same log s...#21304 added a log sanitizer to the server (bridge) code that searches for IP addresses in logs and elides them. We noted in comment:17:ticket:21304 that the other components--client, broker, and proxy-go--can benefit from the same log sanitization.
comment:18:ticket:21304 suggests a way to do it: move the `logScrubber` code into a new top-level subdirectory and `safelog` package, and have the other programs `import git.torproject.org/pluggable-transports/snowflake.git/safelog`.Cecylia BocovichCecylia Bocovichhttps://gitlab.torproject.org/legacy/trac/-/issues/29861Snowflake is not working right now for some reason2020-06-13T18:19:44ZcypherpunksSnowflake is not working right now for some reasonCecylia BocovichCecylia Bocovich