[tor-dev] exitmap modules that make *lots* of connections

[Zack Weinberg]

I'm working on an exitmap module that wants to feed order of 5000
short-lived streams through each exit relay.  I think this is running
foul of some sort of upper limit (in STEM, or in Tor itself, not sure)
on the number of streams a circuit can be used for, or how long, or
something.  What I see in the logs (note: I've modified
eventhandler.py for more detailed debug logs) looks like

2016-04-22 16:07:53,306 [DEBUG]: Circuit status change: CIRC 6
LAUNCHED PURPOSE=GENERAL TIME_CREATED=2016-04-22T20:07:53.305851
2016-04-22 16:07:53,325 [DEBUG]: Circuit status change: CIRC 6
EXTENDED [fp] PURPOSE=GENERAL TIME_CREATED=2016-04-22T20:07:53.305851
2016-04-22 16:07:54,114 [DEBUG]: Circuit status change: CIRC 6
EXTENDED [fp],[fp] PURPOSE=GENERAL
TIME_CREATED=2016-04-22T20:07:53.305851
2016-04-22 16:07:54,115 [DEBUG]: Circuit status change: CIRC 6 BUILT
[fp],[fp] PURPOSE=GENERAL TIME_CREATED=2016-04-22T20:07:53.305851
2016-04-22 16:07:54,136 [DEBUG]: Port 47488 preparing to attach to circuit 6
2016-04-22 16:07:54,136 [DEBUG]: Port 47488 circuit 6 waiting for stream.
2016-04-22 16:07:54,155 [DEBUG]: Attempting to attach stream 65 to circuit 6.
2016-04-22 16:07:54,387 [DEBUG]: Port 47492 preparing to attach to circuit 6
2016-04-22 16:07:54,387 [DEBUG]: Port 47492 circuit 6 waiting for stream.
2016-04-22 16:07:54,388 [DEBUG]: Attempting to attach stream 67 to circuit 6.
2016-04-22 16:07:54,809 [DEBUG]: Port 47496 preparing to attach to circuit 6
2016-04-22 16:07:54,810 [DEBUG]: Port 47496 circuit 6 waiting for stream.
2016-04-22 16:07:54,810 [DEBUG]: Attempting to attach stream 69 to circuit 6.
2016-04-22 16:07:55,060 [DEBUG]: Port 47502 preparing to attach to circuit 6
2016-04-22 16:07:55,060 [DEBUG]: Port 47502 circuit 6 waiting for stream.
2016-04-22 16:07:55,061 [DEBUG]: Attempting to attach stream 72 to circuit 6.
2016-04-22 16:07:55,468 [DEBUG]: Port 47506 preparing to attach to circuit 6
2016-04-22 16:07:55,468 [DEBUG]: Port 47506 circuit 6 waiting for stream.
2016-04-22 16:07:55,469 [DEBUG]: Attempting to attach stream 74 to circuit 6.
2016-04-22 16:07:55,720 [DEBUG]: Port 47508 preparing to attach to circuit 6
2016-04-22 16:07:55,720 [DEBUG]: Port 47508 circuit 6 waiting for stream.
2016-04-22 16:07:55,990 [DEBUG]: Port 47512 preparing to attach to circuit 6
2016-04-22 16:07:55,990 [DEBUG]: Port 47512 circuit 6 waiting for stream.
2016-04-22 16:07:55,990 [DEBUG]: Attempting to attach stream 77 to circuit 6.
2016-04-22 16:07:56,241 [DEBUG]: Port 47518 preparing to attach to circuit 6
2016-04-22 16:07:56,241 [DEBUG]: Port 47518 circuit 6 waiting for stream.
2016-04-22 16:07:56,242 [DEBUG]: Attempting to attach stream 80 to circuit 6.
2016-04-22 16:07:56,492 [DEBUG]: Port 47528 preparing to attach to circuit 6
2016-04-22 16:07:56,492 [DEBUG]: Port 47528 circuit 6 waiting for stream.
2016-04-22 16:07:56,495 [DEBUG]: Attempting to attach stream 85 to circuit 6.
2016-04-22 16:07:56,836 [DEBUG]: Port 47536 preparing to attach to circuit 6
2016-04-22 16:07:56,836 [DEBUG]: Port 47536 circuit 6 waiting for stream.
2016-04-22 16:07:56,836 [DEBUG]: Attempting to attach stream 89 to circuit 6.
2016-04-22 16:07:57,100 [DEBUG]: Port 47540 preparing to attach to circuit 6
2016-04-22 16:07:57,100 [DEBUG]: Attempting to attach stream 91 to circuit 6.
2016-04-22 16:07:57,351 [DEBUG]: Port 47544 preparing to attach to circuit 6
2016-04-22 16:07:57,351 [DEBUG]: Port 47544 circuit 6 waiting for stream.
2016-04-22 16:07:57,352 [DEBUG]: Attempting to attach stream 93 to circuit 6.
2016-04-22 16:07:57,769 [DEBUG]: Port 47550 preparing to attach to circuit 6
2016-04-22 16:07:57,769 [DEBUG]: Port 47550 circuit 6 waiting for stream.
2016-04-22 16:07:57,769 [DEBUG]: Attempting to attach stream 96 to circuit 6.
2016-04-22 16:07:58,118 [DEBUG]: Port 47554 preparing to attach to circuit 6
2016-04-22 16:07:58,118 [DEBUG]: Port 47554 circuit 6 waiting for stream.
2016-04-22 16:07:58,118 [DEBUG]: Attempting to attach stream 98 to circuit 6.
2016-04-22 16:08:04,697 [DEBUG]: Circuit status change: CIRC 6 CLOSED
[fp],[fp] PURPOSE=PATH_BIAS_TESTING
TIME_CREATED=2016-04-22T20:07:53.305851 REASON=FINISHED
2016-04-22 16:08:05,878 [DEBUG]: Port 47690 preparing to attach to circuit 6
2016-04-22 16:08:05,878 [DEBUG]: Port 47690 circuit 6 waiting for stream.
2016-04-22 16:08:05,879 [DEBUG]: Attempting to attach stream 166 to circuit 6.
2016-04-22 16:08:05,879 [WARNING]: Failed to attach stream because:
Unknown circuit "6"

You can see that circuit 6 is no longer available, but the module is
still trying to use it.  It looks like it lasted for almost exactly
ten seconds, which smells like a time limit, but I can't find any
relevant configuration parameters in the documentation.

Rather than trying to make a circuit survive as long as necessary,
which might not even be possible, it'd probably be better if exitmap
could notice that it's lost a circuit that's still in use and create a
new one.  However, I'm not sure how to do that in the current
architecture.  The existing code has "one circuit per module
invocation = one circuit per exit node" as a pretty deeply embedded
design constraint.

Anyone have any ideas?  Full logfile available on request, but it's huge.

zw