Track time between ESTABLISH_RENDEZVOUS and RENDEZVOUS1 cell

In messing with legacy/trac#13193 (moved), I ended up with lines like

Sep 19 02:12:42.656 [info] stats_label_circ(): circ has newly been used for hs: ESTABLISH_RENDEZVOUS
Sep 19 02:12:55.131 [info] stats_label_circ(): circ has newly been used for hs: RENDEZVOUS1

and

Sep 19 02:05:53.253 [info] stats_label_circ(): circ has newly been used for hs: ESTABLISH_RENDEZVOUS
Sep 19 02:05:54.033 [info] stats_label_circ(): circ has newly been used for hs: RENDEZVOUS1

That second one looks pretty good speed-wise, and that first one looks pretty ugly. I assume some of this slow-down is due to legacy/trac#13151 (moved), but I don't know how much.

Wouldn't it be cool to track this delay value over time, to see if things are getting better or worse, to be able to measure how big a deal things like legacy/trac#13151 (moved) are, etc?