[tor-dev] Named pipes with tor

[grarpamp]

> I have the opposite wish case were I would like to have a terminal
> show me the addresses my tor is connecting to in real-time.

The debug log output isn't very useful for logging the final condition
of successful "connection 'requests' in realtime".

As you can see, only the initial 'Client asked for' is really useful
per request. That doesn't mean the request actually resulted in a
ready circuit.

In the case of normal parallel use, none of the log lines are linked
to the parent 'asked for' by any label tag, so it becomes a mashup.

There can be a significant and variable time lag from 'ask for'
until a circuit is created and ready to carry user data.

Storing and parsing the required log levels may be wasteful.

So the debug log isn't going to be very useful as far as knowing
where your socks/natd/trans/dns port requests went, such as to what
exit or last hop to an onion they used. Certainly not for answering
anything beyond 'Client asked for'.

You could simply pipe stdout to any line parser. But that precludes
other uses of that stream, unless you syslog it first.

So what you probably want is to watch the controller output, even
more so once it is enhanced by this ticket:

https://trac.torproject.org/projects/tor/ticket/11179

Example logspam follows...

## first fetch of ip
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <ip1>:80
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp1> at <exitip1> does allow optimistic data for connection to
<ip1>
[info] {APP} connection_ap_process_end_not_open(): Address '<ip1>'
refused due to 'server out of resources'. Considering retrying.
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp2> at <exitip2> does allow optimistic data for connection to
<ip1>
2 BUILT ...,...,<exitfp2>
3 BUILT ...,...,<exitfp1>
9 SUCCEEDED 2 <ip1>:80
# subsequent
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <ip1>:80
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp2> at <exitip2> does allow optimistic data for connection to
<ip1>
9 SUCCEEDED 2 <ip1>:80

## first fetch of fqdn
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <fqdn>:80
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp2> at <exitip2> does allow optimistic data for connection to
<fqdn>
[info] {CONFIG} addressmap_register(): Addressmap: (re)mapped '<fqdn>'
to '<ip2>'
2 BUILT ...,...,<exitfp2>
10 SUCCEEDED 2 <ip2>:80
# subsequent
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <fqdn>:80
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp2> at <exitip2> does allow optimistic data for connection to
<fqdn>
[info] {APP} addressmap_register(): Temporary addressmap ('<fqdn>' to
'<ip2>') not performed, since it's already mapped to '<ip2>'
10 SUCCEEDED 2 <ip2>:80

## first fetch of onion
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <ohash>.onion:80
[info] {REND} connection_ap_handshake_rewrite_and_attach(): Got a
hidden service request for ID '<ohash>'
[info] {REND} connection_ap_handshake_rewrite_and_attach(): Unknown
descriptor <ohash>. Fetching.
[debug] {REND} rend_client_refetch_v2_renddesc(): Fetching v2
rendezvous descriptor for service <ohash>
[info] {REND} directory_get_from_hs_dir(): Sending fetch request for
v2 descriptor for service '<ohash>' with descriptor ID '<desc>', auth
type 0, and descriptor cookie '[none]' to hidden service directory
<dirfp> at <dirip>
[debug] {REND} rend_cache_store_v2_desc_as_client(): Successfully
stored rend desc '<ohash>', len <len>.
[info] {REND} circuit_get_open_circ_or_launch(): Chose <ipfp> at
<ipip> as intro point for '<ohash>'.
[info] {REND} rend_client_note_connection_attempt_ended(): Connection
attempt for <ohash> has ended; cleaning up temporary state.
5 BUILT ...,...,<exitfp0>
11 SUCCEEDED 5 <ohash>.onion:80
# subsequent
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <ohash>.onion:80
[info] {REND} connection_ap_handshake_rewrite_and_attach(): Got a
hidden service request for ID '<ohash>'
[info] {REND} rend_client_note_connection_attempt_ended(): Connection
attempt for <ohash> has ended; cleaning up temporary state.
11 SUCCEEDED 5 <ohash>.onion:80

## first fetch of dnsfwd
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <dnsfwd>:0
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp> at <exitip> does allow optimistic data for connection to
<dnsfwd>
[info] {CONFIG} addressmap_register(): Addressmap: (re)mapped
'<dnsfwd>' to '<dnsrev>'
# subsequent
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <dnsfwd>:0
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp> at <exitip> does allow optimistic data for connection to
<dnsfwd>
[info] {APP} addressmap_register(): Temporary addressmap ('<dnsfwd>'
to '<dnsrev>') not performed, since it's already mapped to '<dnsrev>'

## first fetch of dnsrev
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <dnsrev>:0
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp> at <exitip> does allow optimistic data for connection to
<dnsrev>
[info] {CONFIG} addressmap_register(): Addressmap: (re)mapped
'REVERSE[<dnsrev>]' to '<dnsresult>'
# subsequent
[debug] {APP} connection_ap_handshake_rewrite_and_attach(): Client
asked for <dnsrev>:0
[info] {APP} link_apconn_to_circ(): Looks like completed circuit to
<exitfp> at <exitip> does allow optimistic data for connection to
<dnsrev>
[info] {APP} addressmap_register(): Temporary addressmap
('REVERSE[<dnsrev>]' to '<dnsresult>') not performed, since it's
already mapped to '<dnsresult>'