[tor-bugs] #5552 [Tor Client]: Reported amount of uploaded data occasionally inflated by several gigabytes

[Tor Bug Tracker & Wiki]

#5552: Reported amount of uploaded data occasionally inflated by several gigabytes
------------------------+---------------------------------------------------
 Reporter:  fk          |          Owner:                     
     Type:  defect      |         Status:  new                
 Priority:  normal      |      Milestone:                     
Component:  Tor Client  |        Version:  Tor: 0.2.3.13-alpha
 Keywords:              |         Parent:                     
   Points:              |   Actualpoints:                     
------------------------+---------------------------------------------------
 In December I started noticing in Arm that the total amount of uploaded
 data reported by my Tor client would occasionally jump by several
 gigabytes while I wasn't looking.

 I'm currently using a very poor and easily saturated Internet connection
 through WCDMA, often I merely get around 4 kbytes/s in both directions,
 frequent packet loss and several seconds of RTT. It is thus rather
 unlikely that my Tor client will ever upload several gigabytes without
 being restarted.

 My impression is that the pathetic connectivity has something to do with
 the problem. The frequency of the error message seems to be higher if the
 performance of the Internet connection is poor.

 The inflated bandwidth seems to be the result of Tor casting a negative
 number to size_t, my current workaround (attached) is to let it detect
 this and reset the bytes_written to 0 instead.

 In the log it looks like this:
 Mar 31 17:41:57.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 2805925, stats_prev_n_written: 2806123
 Mar 31 17:59:00.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 3387774, stats_prev_n_written: 3387972
 Mar 31 17:59:05.977 [err] {GENERAL} Resetting bytes_written from
 -396/4294966900 to 0. cur_written: 3415804, stats_prev_n_written: 3416200
 Mar 31 17:59:55.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 3581843, stats_prev_n_written: 3582041
 Mar 31 17:59:59.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 3591359, stats_prev_n_written: 3591557
 Mar 31 18:00:00.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 3591161, stats_prev_n_written: 3591359
 Mar 31 18:25:03.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 4002667, stats_prev_n_written: 4002865
 Mar 31 18:54:02.977 [err] {GENERAL} Resetting bytes_written from
 -198/4294967098 to 0. cur_written: 4519483, stats_prev_n_written: 4519681

 The negative number seems to be -198 most of the time, but I've seen
 values ranging between -8 and -990.

 I'm usually using the latest alpha release, currently Tor 0.2.3.13-alpha
 with libevent 2.0.16 on FreeBSD 10.0-CURRENT amd64.

 I have (currently unsanitized) logs with log level [app]debug lying
 around, so if there are specific messages you are interested in I can
 probably look them up. I've seen no obvious correlations, though.

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