[tor-bugs] #32576 [Circumvention/Snowflake]: Snowflake broker not serving metrics correctly

[Tor Bug Tracker & Wiki]

#32576: Snowflake broker not serving metrics correctly
-------------------------------------+---------------------------
 Reporter:  cohosh                   |          Owner:  cohosh
     Type:  defect                   |         Status:  assigned
 Priority:  Very High                |      Milestone:
Component:  Circumvention/Snowflake  |        Version:
 Severity:  Normal                   |     Resolution:
 Keywords:  metrics                  |  Actual Points:
Parent ID:                           |         Points:
 Reviewer:                           |        Sponsor:  Sponsor28
-------------------------------------+---------------------------

Comment (by cohosh):

 Alright I found what look like a few crashes:
 {{{
 >[scrubbed]: read: connection reset by peer
 panic: runtime error: index out of range

 goroutine 360108 [running]:
 main.SnowflakeHeap.Swap(0xc001440200, 0x10, 0x40, 0xffffffffffffffff, 0xf)
         /home/david/branches/snowflake/broker/snowflake-heap.go:30 +0x8a
 container/heap.Remove(0x7bc1c0, 0xc00007abe0, 0xffffffffffffffff, 0x1,
 0xc00007c601)
         /usr/lib/go-1.11/src/container/heap/heap.go:75 +0x9c
 main.(*BrokerContext).Broker.func1(0xc000ef4240, 0xc00007ac00,
 0xc00111e5e0)
         /home/david/branches/snowflake/broker/broker.go:129 +0x128
 created by main.(*BrokerContext).Broker
         /home/david/branches/snowflake/broker/broker.go:122 +0xa2
 }}}

 {{{
 2019/11/15 12:25:29 http2: received GOAWAY [FrameHeader GOAWAY len=8],
 starting graceful shutdown
 fatal error: concurrent map writes
 }}}

 {{{
 2019/11/15 17:23:46 http: TLS handshake error from [scrubbed]: EOF
 panic: runtime error: index out of range

 goroutine 1949618 [running]:
 main.SnowflakeHeap.Swap(0xc003e08400, 0x20, 0x40, 0xffffffffffffffff,
 0x1f)
         /home/david/branches/snowflake/broker/snowflake-heap.go:30 +0x8a
 container/heap.Remove(0x7bc1c0, 0xc00000cc00, 0xffffffffffffffff, 0x1,
 0xc001de4f01)
         /usr/lib/go-1.11/src/container/heap/heap.go:75 +0x9c
 main.(*BrokerContext).Broker.func1(0xc004d065a0, 0xc00000cc20,
 0xc004b03300)
         /home/david/branches/snowflake/broker/broker.go:129 +0x128
 created by main.(*BrokerContext).Broker
         /home/david/branches/snowflake/broker/broker.go:122 +0xa2
 }}}
 {{{
 2019/11/15 18:03:08 http: TLS handshake error from [scrubbed]: read tcp
 [scrubbed]->[scrubbed]: read:
  connection reset by peer
 fatal error: concurrent map writes
 }}}

 ... and so on, pretty much continuously through to today:
 {{{
 2019/11/22 10:15:44 http: TLS handshake error from [scrubbed]: EOF
 fatal error: concurrent map writes
 }}}

 The weird thing is, these errors don't occur on the old broker host:
 /var/log/snowflake-broker# grep "fatal error" ./*
 /var/log/snowflake-broker# grep "panic" ./*
 both yield no results.

 The frequency with which the panics on the new host occur explain the lack
 of metrics, we only log metrics once the broker has been running for 24
 hours straight and that hasn't happened since 14-11-2019.

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/32576#comment:2>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online