Two minutes after a failed hidserv connection, we do a bonus hsdesc fetch
If you do the steps to reproduce #14219 (moved), you end up eventually hanging up on the hidden service stream attempt: your controller events include
1421356924.815634 [torctl-log] localhost:9051 650 HS_DESC REQUESTED yjiqkj6p7drpiwyq NO_AUTH $0B5E5E70FFEA9C7F9FFD13B8E16916A608F3E9EB~CalyxInstitute08 blwd4dzs2mnncf4wtc3bpv6pljwx5awb
1421356925.596473 [torctl-log] localhost:9051 650 HS_DESC RECEIVED yjiqkj6p7drpiwyq NO_AUTH $0B5E5E70FFEA9C7F9FFD13B8E16916A608F3E9EB~CalyxInstitute08
and your Tor debug log says
Jan 15 16:22:05.595 [info] connection_dir_client_reached_eof(): Received rendezvous descriptor (size 3254, status 200 ("OK"))
Jan 15 16:22:05.596 [info] rend_cache_store_v2_desc_as_client(): We already have a new enough service descriptor for service ID yjiqkj6p7drpiwyq with the same desc ID and version.
Jan 15 16:22:05.596 [info] connection_dir_client_reached_eof(): Successfully fetched v2 rendezvous descriptor.
Jan 15 16:22:05.596 [notice] Closing stream for 'yjiqkj6p7drpiwyq.onion': hidden service is unavailable (try again later).
Jan 15 16:22:05.596 [info] rend_client_note_connection_attempt_ended(): Connection attempt for yjiqkj6p7drpiwyq has ended; cleaning up temporary state.
Jan 15 16:22:05.596 [info] rend_client_note_connection_attempt_ended(): Connection attempt for yjiqkj6p7drpiwyq has ended; cleaning up temporary state.
and then your application stream gets closed.
Then two minutes later (!), you see these controller events:
1421357045.919921 [torctl-log] localhost:9051 650 HS_DESC REQUESTED yjiqkj6p7drpiwyq NO_AUTH $0B569B9F3999ACA1E7F52EA2C41841F9DDA89C3D~Unnamed blwd4dzs2mnncf4wtc3bpv6pljwx5awb
1421357047.114483 [torctl-log] localhost:9051 650 HS_DESC RECEIVED yjiqkj6p7drpiwyq NO_AUTH $0B569B9F3999ACA1E7F52EA2C41841F9DDA89C3D~Unnamed
It turns out that happens because the intro circuit finally closes:
Jan 15 16:24:05.918 [info] circuit_expire_building(): Abandoning circ 5 195.154.127.246:9001:2375802890 (state 1,3:open, purpose 6, len 6)
Jan 15 16:24:05.918 [info] internal circ (length 6): $4FEE77AFFD157BBCF2D896AE417FBF647860466C(open) $F4F605AA21C4633CCB5B8DBBC1CEEE5C590C6DCE(open) $B6D30CEC9F8FAB676CCD0634DC86412F1BA8F4D2(open) $5B3B9A0EA1DC16F6348C57FCC83BBB43D1013F4A(open) $10B6A20E3F1D0C0742053A19242AB61586A5B9B4(open) $D51C1F3A39FB0BCA12D2795F67B1FA93A750218D(open)
which is reasonable, except, then:
Jan 15 16:24:05.918 [info] circuit_mark_for_close_(): Failed intro circ yjiqkj6p7drpiwyq to $D51C1F3A39FB0BCA12D2795F67B1FA93A750218D (building circuit to intro point). Marking intro point as possibly unreachable.
Jan 15 16:24:05.918 [info] rend_client_report_intro_point_failure(): Unknown service "yjiqkj6p7drpiwyq". Re-fetching descriptor.
Jan 15 16:24:05.918 [debug] rend_client_refetch_v2_renddesc(): Fetching v2 rendezvous descriptor for service yjiqkj6p7drpiwyq
It looks like the closing of the intro circuit, 2 minutes later, triggers another fetching of a descriptor!