Skip to content

GitLab

Open
Created by Karsten Loesing@karsten

Circuit build time reported by metrics is sometimes off

I'm currently testing my Torperf rewrite. I noticed that a few circuit builds take far longer than the circuit-build timeout. Still, these circuit builds are not aborted and the resulting circuits get streams attached. Isn't the CBT stuff supposed to prevent just that?

Below is an example (reformatted). Notice the timestamps of the CIRC LAUNCHED and the CIRC EXTENDED event:

2013-03-26 12:57:05+0000 CIRC 176 LAUNCHED
  BUILD_FLAGS=NEED_CAPACITY PURPOSE=GENERAL
  TIME_CREATED=2013-03-26T12:57:05.992579
2013-03-26 12:58:44+0000 CIRC 176 EXTENDED
  $8BBE900C29D4B5D3FC727DB65140EA0A5EC94C19=kennkeintor
  BUILD_FLAGS=NEED_CAPACITY PURPOSE=GENERAL
  TIME_CREATED=2013-03-26T12:57:05.992579
2013-03-26 12:58:44+0000 CIRC 176 EXTENDED
  $8BBE900C29D4B5D3FC727DB65140EA0A5EC94C19=kennkeintor,
  $0AC01745501396F338291248032E77317079A02D=KandHResearchCo
  BUILD_FLAGS=NEED_CAPACITY PURPOSE=GENERAL
  TIME_CREATED=2013-03-26T12:57:05.992579
2013-03-26 12:58:45+0000 CIRC 176 EXTENDED
  $8BBE900C29D4B5D3FC727DB65140EA0A5EC94C19=kennkeintor,
  $0AC01745501396F338291248032E77317079A02D=KandHResearchCo,
  $3E5693C4B0FCD8B42153869494421164E42A9FE0=chaoscomputerclub29
  BUILD_FLAGS=NEED_CAPACITY PURPOSE=GENERAL
  TIME_CREATED=2013-03-26T12:57:05.992579
2013-03-26 12:58:45+0000 CIRC 176 BUILT
  $8BBE900C29D4B5D3FC727DB65140EA0A5EC94C19=kennkeintor,
  $0AC01745501396F338291248032E77317079A02D=KandHResearchCo,
  $3E5693C4B0FCD8B42153869494421164E42A9FE0=chaoscomputerclub29
  BUILD_FLAGS=NEED_CAPACITY PURPOSE=GENERAL
  TIME_CREATED=2013-03-26T12:57:05.992579
2013-03-26 13:01:01+0000 STREAM 379 SENTCONNECT 176
  54.242.189.124:80
2013-03-26 13:01:02+0000 STREAM 379 REMAP 176 54.242.189.124:80
  SOURCE=EXIT
2013-03-26 13:01:02+0000 STREAM 379 SUCCEEDED 176 54.242.189.124:80
2013-03-26 13:01:04+0000 STREAM 379 CLOSED 176 54.242.189.124:80
  REASON=END REMOTE_REASON=DONE
2013-03-26 13:02:09+0000 CIRC 176 CLOSED
  $8BBE900C29D4B5D3FC727DB65140EA0A5EC94C19=kennkeintor,
  $0AC01745501396F338291248032E77317079A02D=KandHResearchCo,
  $3E5693C4B0FCD8B42153869494421164E42A9FE0=chaoscomputerclub29
  BUILD_FLAGS=NEED_CAPACITY PURPOSE=GENERAL
  TIME_CREATED=2013-03-26T12:57:05.992579 REASON=FINISHED

The CBT was around 3 seconds at that time as reported in a BUILDTIMEOUT_SET event. This is Tor version 0.2.4.9-alpha-dev (git-123daffb). I can easily modify and re-run this tool to gather more data if required.

Edited by Mike Perry
To upload designs, you'll need to enable LFS and have an admin enable hashed storage. More information