Proxy hourly stats did not actually happen during that hour
My snowflake proxy today said in its logs:
2023/10/27 09:53:58 In the last 1h0m0s, there were 53 connections. Traffic Relayed ↓ 999064 KB, ↑ 167798 KB.
2023/10/27 10:53:58 In the last 1h0m0s, there were 67 connections. Traffic Relayed ↓ 561833 KB, ↑ 97282 KB.
2023/10/27 11:53:58 In the last 1h0m0s, there were 63 connections. Traffic Relayed ↓ 124717270 KB, ↑ 6237157 KB.
2023/10/27 12:53:58 In the last 1h0m0s, there were 48 connections. Traffic Relayed ↓ 745608 KB, ↑ 97699 KB.
That "125 gigabytes" entry translates to... almost 35 megabytes per second of traffic, on average during the hour? Probably by only a few or even one user? This did not happen during that hour.
Looking at proxy/lib/pt_event_logger.go:
case event.EventOnProxyConnectionOver:
e := e.(event.EventOnProxyConnectionOver)
p.inboundSum += e.InboundTraffic
p.outboundSum += e.OutboundTraffic
p.connectionCount += 1
I.e. what is happening here is that the stats for the entire connection are counted during the hour that it closed.
See the forum for somebody else reporting this same issue (forum post noticed courtesy MarkC on irc): https://forum.torproject.org/t/impossible-metric-for-snowflake-proxy/9941/1
We should either (a) make the hourly "In the last 1h0m0s," be accurate, in the sense that they actually tell me what happened in the last 1h0m0s, or (b) change the log message so it's clearer it is telling me how many connections finished during that hour along with total transfer on those recently-closed connections.
I'd prefer solution 'a', since it is what I thought I was getting out of these log entries, and I was using it to e.g. try to judge what timezones my snowflake is popular.