Aug 16 09:30:48.000 [notice] Tor 0.2.4.23 opening new log file. Aug 16 09:35:47.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:35:47.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:35:47.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20fb1c00 (global ID 0) Aug 16 09:35:47.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x23124bc0 for circ_id 2147500130, channel ID 0 (0x20fb1c00) Aug 16 09:35:47.000 [debug] circuit_receive_relay_cell(): Sending to origin. Aug 16 09:35:47.000 [debug] connection_edge_process_relay_cell(): Now seen 4142 relay cells here (command 15, stream 0). Aug 16 09:35:47.000 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Aug 16 09:35:47.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:35:47.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $0045CDEB9EBC25420E5B5A8AAD574EFAE07A4FC8(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:35:47.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:35:47.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:35:47.000 [debug] relay_send_command_from_edge_(): delivering 14 cell forward. Aug 16 09:35:47.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 6 remaining. Aug 16 09:35:47.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:35:47.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:35:47.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:35:47.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:35:47.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:35:47.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:35:47.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:35:47.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:35:47.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:35:47.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:35:47.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:47.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:35:47.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:35:47.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:35:47.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:35:48.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:49.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:50.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:51.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:52.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:52.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:53.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:35:53.000 [debug] connection_read_to_buf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:35:53.000 [debug] TLS error: unexpected close while reading (SSL negotiation finished successfully) Aug 16 09:35:53.000 [debug] tor_tls_read(): read returned r=0, err=-8 Aug 16 09:35:53.000 [debug] connection_read_to_buf(): TLS connection closed on read. Closing. (Nickname Y, address 178.77.98.124) Aug 16 09:35:53.000 [debug] channel_close_for_error(): Closing channel 0x235ec780 due to lower-layer error Aug 16 09:35:53.000 [debug] channel_change_state(): Changing state of channel 0x235ec780 (global ID 4) from "open" to "closing" Aug 16 09:35:53.000 [debug] channel_remove_from_digest_map(): Removed channel 0x235ec780 (global ID 4) from identity map in state closing (4) with digest F880903C178145316BDD1542C4CB6182E9825EDE Aug 16 09:35:53.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection.c:2865 Aug 16 09:35:53.000 [debug] conn_close_if_marked(): Cleaning up connection (fd -1). Aug 16 09:35:53.000 [debug] channel_change_state(): Changing state of channel 0x235ec780 (global ID 4) from "closing" to "channel error" Aug 16 09:35:53.000 [debug] connection_remove(): removing socket -1 (type OR), n_conns now 11 Aug 16 09:35:53.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:53.000 [debug] channel_free(): Freeing channel 4 at 0x235ec780 Aug 16 09:35:53.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x235ec780 with global ID 4 Aug 16 09:35:53.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:53.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:35:53.000 [debug] connection_read_to_buf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:35:53.000 [debug] TLS error: unexpected close while reading (SSL negotiation finished successfully) Aug 16 09:35:53.000 [debug] tor_tls_read(): read returned r=0, err=-8 Aug 16 09:35:53.000 [debug] connection_read_to_buf(): TLS connection closed on read. Closing. (Nickname hammett, address 188.226.197.224) Aug 16 09:35:53.000 [debug] channel_close_for_error(): Closing channel 0x2093adc0 due to lower-layer error Aug 16 09:35:53.000 [debug] channel_change_state(): Changing state of channel 0x2093adc0 (global ID 5) from "open" to "closing" Aug 16 09:35:53.000 [debug] channel_remove_from_digest_map(): Removed channel 0x2093adc0 (global ID 5) from identity map in state closing (4) with digest 0FA72BDDCDA850B92EF15CD94054AD8FEF4E766D Aug 16 09:35:53.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection.c:2865 Aug 16 09:35:53.000 [debug] conn_close_if_marked(): Cleaning up connection (fd -1). Aug 16 09:35:53.000 [debug] channel_change_state(): Changing state of channel 0x2093adc0 (global ID 5) from "closing" to "channel error" Aug 16 09:35:53.000 [debug] connection_remove(): removing socket -1 (type OR), n_conns now 10 Aug 16 09:35:54.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:54.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:54.000 [debug] channel_free(): Freeing channel 5 at 0x2093adc0 Aug 16 09:35:54.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x2093adc0 with global ID 5 Aug 16 09:35:54.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:55.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:55.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:56.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:56.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:57.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:57.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:57.000 [info] Monitored process 4046 is still alive. Aug 16 09:35:58.000 [info] update_consensus_router_descriptor_downloads(): 1 router descriptors downloadable. 0 delayed; 6054 present (0 of those were in old_routers); 0 would_reject; 0 wouldnt_use; 0 in progress. Aug 16 09:35:58.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:58.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:35:59.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:35:59.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:00.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:00.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:01.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:36:01.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:01.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:01.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:01.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:01.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:01.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:01.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:01.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:01.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:02.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:02.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:03.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:03.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:04.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:04.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:05.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:05.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:06.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:06.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:07.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:07.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:08.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:08.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:08.000 [debug] conn_read_callback(): socket 21 wants to read. Aug 16 09:36:08.000 [debug] connection_read_to_buf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:08.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:08.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:08.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20fb1c00 (global ID 0) Aug 16 09:36:08.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x23124bc0 for circ_id 2147500130, channel ID 0 (0x20fb1c00) Aug 16 09:36:08.000 [debug] circuit_receive_relay_cell(): Sending to origin. Aug 16 09:36:08.000 [debug] connection_edge_process_relay_cell(): Now seen 4143 relay cells here (command 9, stream 0). Aug 16 09:36:08.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x23124bc0 for circ_id 2147500130, channel ID 0 (0x20fb1c00) Aug 16 09:36:08.000 [info] circuit_testing_failed(): Our testing circuit (to see if your ORPort is reachable) has failed. I'll try again later. Aug 16 09:36:08.000 [debug] channel_send_destroy(): Sending destroy (circID 2147500130) on channel 0x20fb1c00 (global ID 0) Aug 16 09:36:08.000 [debug] channel_write_cell(): Writing cell_t 0xb1f108 to channel 0x20fb1c00 with global ID 0 Aug 16 09:36:08.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:08.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:36:08.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:36:08.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:36:08.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:09.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:09.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:36:09.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:09.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:36:09.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:09.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:10.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:10.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:11.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:11.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:12.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:12.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:12.000 [info] Monitored process 4046 is still alive. Aug 16 09:36:13.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:13.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:14.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:14.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:15.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:15.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:16.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:36:16.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:16.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:16.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:16.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:16.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:16.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:16.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:16.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:16.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:17.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:17.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:18.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:18.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:19.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:19.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:20.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:20.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:21.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:21.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:22.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:22.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:23.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:23.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:24.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:24.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:25.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:25.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:25.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:26.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:26.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:27.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:27.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:27.000 [info] Monitored process 4046 is still alive. Aug 16 09:36:28.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:28.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:29.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:29.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:30.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:30.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:31.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:36:31.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:31.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:31.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:31.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:31.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:31.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:31.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:31.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:31.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:32.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:32.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:33.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:33.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:34.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:34.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:35.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:35.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:36.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:36.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:37.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:37.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:38.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:38.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:39.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:39.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:40.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:40.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:41.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:41.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:42.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:42.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:42.000 [info] Monitored process 4046 is still alive. Aug 16 09:36:43.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:43.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:44.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:44.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:45.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:45.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:46.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:36:46.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:46.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:46.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:46.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:46.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:46.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:46.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:46.000 [debug] count_usable_descriptors(): 6049 usable, 6048 present (descs). Aug 16 09:36:46.000 [debug] count_usable_descriptors(): 1127 usable, 1126 present (desc exits). Aug 16 09:36:46.000 [debug] count_usable_descriptors(): 1127 usable, 1126 present (desc exits). Aug 16 09:36:46.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as guard based on weights Wg=0.570800 Wm=0.570800 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:36:46.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as middle node based on weights Wg=0.429200 Wm=1.000000 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:36:46.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as exit based on weights Wg=0.843900 Wm=1.000000 We=1.000000 Wd=0.843900 with total bw 0 Aug 16 09:36:46.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as exit based on weights Wg=0.843900 Wm=1.000000 We=1.000000 Wd=0.843900 with total bw 0 Aug 16 09:36:46.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:46.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 29 (185.57.82.25:9001) [idle 180]. Aug 16 09:36:46.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1187 Aug 16 09:36:46.000 [debug] channel_close_from_lower_layer(): Closing channel 0x20951100 (global ID 6) due to lower-layer event Aug 16 09:36:46.000 [debug] channel_change_state(): Changing state of channel 0x20951100 (global ID 6) from "open" to "closing" Aug 16 09:36:46.000 [debug] channel_remove_from_digest_map(): Removed channel 0x20951100 (global ID 6) from identity map in state closing (4) with digest F86EE82830353A0A26374FA6DA94DD1551F0DA0F Aug 16 09:36:46.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 29). Aug 16 09:36:46.000 [debug] channel_change_state(): Changing state of channel 0x20951100 (global ID 6) from "closing" to "closed" Aug 16 09:36:46.000 [debug] connection_remove(): removing socket 29 (type OR), n_conns now 9 Aug 16 09:36:46.000 [debug] connection_free_(): closing fd 29. Aug 16 09:36:46.000 [debug] channel_free(): Freeing channel 6 at 0x20951100 Aug 16 09:36:46.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x20951100 with global ID 6 Aug 16 09:36:46.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:47.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:47.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:48.000 [debug] resolve_my_address(): Guessed local host name as 'MAINMACHINE' Aug 16 09:36:48.000 [info] resolve_my_address(): Guessed local hostname 'MAINMACHINE' resolves to a private IP address (192.168.0.2). Trying something else. Aug 16 09:36:48.000 [info] resolve_my_address(): Could not get local interface IP address. Too bad. Aug 16 09:36:48.000 [info] resolve_my_address(): Address 'MAINMACHINE' resolves to private IP address '192.168.0.2'. Tor servers that use the default DirAuthorities must have public IP addresses. Aug 16 09:36:48.000 [info] check_descriptor_ipaddress_changed(): options->Address didn't resolve into an IP. Aug 16 09:36:48.000 [info] consider_testing_reachability(): Testing reachability of my ORPort: 68.81.151.17:9001. Aug 16 09:36:48.000 [debug] new_route_len(): Chosen route length 3 (6053/6055 routers suitable). Aug 16 09:36:48.000 [info] onion_pick_cpath_exit(): Using requested exit node '$B87C11E2ECB617289BA4F24EFAB85C339232ED38~Brrraaaap at 68.81.151.17' Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Path is 0 long; we want 3 Aug 16 09:36:48.000 [debug] extend_info_from_node(): using 5.135.59.74:80 for onion Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Chose router $704386F528CD7C31F8A46664A543A8A1513C949D~onion at 5.135.59.74 for hop 1 (exit is Brrraaaap) Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Path is 1 long; we want 3 Aug 16 09:36:48.000 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice. Aug 16 09:36:48.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as middle node based on weights Wg=0.429200 Wm=1.000000 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:36:48.000 [debug] extend_info_from_node(): using 46.165.223.227:443 for aKUQjBSirrOzHYia Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Chose router $E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F~aKUQjBSirrOzHYia at 46.165.223.227 for hop 2 (exit is Brrraaaap) Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Path is 2 long; we want 3 Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Chose router $B87C11E2ECB617289BA4F24EFAB85C339232ED38~Brrraaaap at 68.81.151.17 for hop 3 (exit is Brrraaaap) Aug 16 09:36:48.000 [debug] onion_extend_cpath(): Path is complete: 3 steps long Aug 16 09:36:48.000 [debug] circuit_handle_first_hop(): Looking for firsthop '5.135.59.74:80' Aug 16 09:36:48.000 [debug] circuit_handle_first_hop(): Conn open. Delivering first onion skin. Aug 16 09:36:48.000 [debug] circuit_send_next_onion_skin(): First skin; sending create cell. Aug 16 09:36:48.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found nothing for circ_id 2147485933, channel ID 1 (0x21983820) Aug 16 09:36:48.000 [debug] circuit_deliver_create_cell(): Chosen circID 2147485933. Aug 16 09:36:48.000 [debug] circuitmux_attach_circuit(): Attaching circuit 2147485933 on channel 1 to cmux 0x21542ca0 Aug 16 09:36:48.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:36:48.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:36:48.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x21983820 with global ID 1 Aug 16 09:36:48.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:36:48.000 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to '$704386F528CD7C31F8A46664A543A8A1513C949D~onion at 5.135.59.74' Aug 16 09:36:48.000 [info] routerlist_remove_old_routers(): We have 6054 live routers and 2809 old router descriptors. Aug 16 09:36:48.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:48.000 [info] buf_shrink_freelists(): Cleaned freelist for 4096-byte chunks: original length 10, kept 9, dropped 1. Aug 16 09:36:48.000 [debug] conn_write_callback(): socket 24 wants to write. Aug 16 09:36:48.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:36:48.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:36:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:36:48.000 [debug] conn_read_callback(): socket 24 wants to read. Aug 16 09:36:48.000 [debug] connection_read_to_buf(): 24: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:48.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:48.000 [debug] connection_or_process_cells_from_inbuf(): 24: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:48.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x21983820 (global ID 1) Aug 16 09:36:48.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x2093be80 for circ_id 2147485933, channel ID 1 (0x21983820) Aug 16 09:36:48.000 [debug] command_process_created_cell(): at OP. Finishing handshake. Aug 16 09:36:48.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:36:48.000 [info] internal circ (length 3, last hop Brrraaaap): $704386F528CD7C31F8A46664A543A8A1513C949D(open) $E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F(closed) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:36:48.000 [debug] command_process_created_cell(): Moving to next skin. Aug 16 09:36:48.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:36:48.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:36:48.000 [debug] relay_send_command_from_edge_(): delivering 14 cell forward. Aug 16 09:36:48.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 6 remaining. Aug 16 09:36:48.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:36:48.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:36:48.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:36:48.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x21983820 with global ID 1 Aug 16 09:36:48.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:36:48.000 [debug] connection_or_process_cells_from_inbuf(): 24: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:48.000 [debug] conn_write_callback(): socket 24 wants to write. Aug 16 09:36:48.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:36:48.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:36:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:36:48.000 [debug] conn_read_callback(): socket 24 wants to read. Aug 16 09:36:48.000 [debug] connection_read_to_buf(): 24: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:48.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:48.000 [debug] connection_or_process_cells_from_inbuf(): 24: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:48.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x21983820 (global ID 1) Aug 16 09:36:48.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x2093be80 for circ_id 2147485933, channel ID 1 (0x21983820) Aug 16 09:36:48.000 [debug] circuit_receive_relay_cell(): Sending to origin. Aug 16 09:36:48.000 [debug] connection_edge_process_relay_cell(): Now seen 4144 relay cells here (command 15, stream 0). Aug 16 09:36:48.000 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Aug 16 09:36:48.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:36:48.000 [info] internal circ (length 3, last hop Brrraaaap): $704386F528CD7C31F8A46664A543A8A1513C949D(open) $E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:36:48.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:36:48.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:36:48.000 [debug] relay_send_command_from_edge_(): delivering 14 cell forward. Aug 16 09:36:48.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 5 remaining. Aug 16 09:36:48.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:36:48.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:36:48.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:36:48.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:36:48.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x21983820 with global ID 1 Aug 16 09:36:48.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:36:48.000 [debug] connection_or_process_cells_from_inbuf(): 24: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:48.000 [debug] conn_write_callback(): socket 24 wants to write. Aug 16 09:36:48.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:36:48.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:36:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:48.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:36:49.000 [debug] conn_read_callback(): socket 17 wants to read. Aug 16 09:36:49.000 [debug] connection_handle_listener_read(): Connection accepted on socket 27 (child of fd 17). Aug 16 09:36:49.000 [debug] connection_add_impl(): new conn type OR, socket 27, address 46.165.223.227, n_conns 9. Aug 16 09:36:49.000 [debug] channel_register(): Registering channel 0x20960680 (ID 8) in state opening (1) with digest 0000000000000000000000000000000000000000 Aug 16 09:36:49.000 [info] channel_register(): Channel 0x20960680 (global ID 8) in state opening (1) registered with no identity digest Aug 16 09:36:49.000 [debug] channel_listener_queue_incoming(): Queueing incoming channel 0x20960680 (global ID 8) on channel listener 0x2093be20 (global ID 3) Aug 16 09:36:49.000 [debug] channel_set_cell_handlers(): Setting cell_handler callback for channel 0x20960680 to 0x1676c5 Aug 16 09:36:49.000 [debug] channel_set_cell_handlers(): Setting var_cell_handler callback for channel 0x20960680 to 0x166d8e Aug 16 09:36:49.000 [debug] connection_tls_start_handshake(): starting TLS handshake on fd 27 Aug 16 09:36:49.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x20950e40 (before/accept initialization) Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state before/accept initialization [type=16,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state before/accept initialization [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv2/v3 read client hello A [type=8194,val=-1]. Aug 16 09:36:49.000 [debug] tor_tls_handshake(): After call, 0x20950e40 was in state SSLv2/v3 read client hello A Aug 16 09:36:49.000 [debug] connection_tls_continue_handshake(): wanted read Aug 16 09:36:49.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:36:49.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x20950e40 (SSLv2/v3 read client hello A) Aug 16 09:36:49.000 [debug] tor_tls_classify_client_ciphers(): Got a non-version-1 cipher called 'ECDHE-ECDSA-AES128-GCM-SHA256' Aug 16 09:36:49.000 [debug] tor_tls_classify_client_ciphers(): Got a real V2/V3 cipher list from [scrubbed]. It is: 'ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:ECDHE-RSA-DES-CBC3-SHA:ECDHE-ECDSA-RC4-SHA:ECDHE-RSA-RC4-SHA:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA:DHE-RSA-CAMELLIA128-SHA:DHE-RSA-AES256-SHA:DHE-DSS-AES256-SHA:DHE-RSA-CAMELLIA256-SHA:EDH-RSA-DES-CBC3-SHA:AES128-SHA:CAMELLIA128-SHA:AES256-SHA:CAMELLIA256-SHA:DES-CBC3-SHA:RC4-SHA:RC4-MD5' Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 read client hello A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 write server hello A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 write certificate A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 write key exchange A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 write server done A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 flush data [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 read client certificate A [type=8194,val=-1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 read client certificate A [type=8194,val=-1]. Aug 16 09:36:49.000 [debug] tor_tls_handshake(): After call, 0x20950e40 was in state SSLv3 read client certificate A Aug 16 09:36:49.000 [debug] connection_tls_continue_handshake(): wanted read Aug 16 09:36:49.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:36:49.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x20950e40 (SSLv3 read client certificate A) Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 read client key exchange A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 read finished A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 write change cipher spec A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 write finished A [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSLv3 flush data [type=8193,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSL negotiation finished successfully [type=32,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_debug_state_callback(): SSL 0x20952fe0 is now in state SSL negotiation finished successfully [type=8194,val=1]. Aug 16 09:36:49.000 [debug] tor_tls_handshake(): After call, 0x20950e40 was in state SSL negotiation finished successfully Aug 16 09:36:49.000 [debug] tor_tls_finish_handshake(): Completed V2 TLS handshake with client; waiting for renegotiation. Aug 16 09:36:49.000 [debug] connection_tls_continue_handshake(): Done with initial SSL handshake (server-side). Expecting renegotiation or VERSIONS cell Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:49.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:49.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:36:49.000 [debug] connection_read_to_buf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:36:49.000 [debug] connection_read_to_buf(): After TLS read of 9: 400 read, 801 written Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 9 (0 pending in tls object). Aug 16 09:36:49.000 [info] channel_tls_process_versions_cell(): Negotiated version 4 with [scrubbed]:35786; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:49.000 [debug] conn_write_callback(): socket 27 wants to write. Aug 16 09:36:49.000 [debug] flush_chunk_tls(): flushed 1467 bytes, 0 ready to flush, 0 remain. Aug 16 09:36:49.000 [debug] connection_handle_write_impl(): After TLS write of 1467: 0 read, 1496 written Aug 16 09:36:49.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:49.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:36:49.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:49.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:36:49.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:36:49.000 [debug] connection_read_to_buf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:49.000 [debug] connection_read_to_buf(): After TLS read of 1787: 1816 read, 0 written Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 1787 (0 pending in tls object). Aug 16 09:36:49.000 [info] channel_tls_process_certs_cell(): Got some good certificates from [scrubbed]:35786: Waiting for AUTHENTICATE. Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 877 (0 pending in tls object). Aug 16 09:36:49.000 [debug] channel_set_identity_digest(): Setting remote endpoint digest on channel 0x20960680 with global ID 8 to digest E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F Aug 16 09:36:49.000 [debug] channel_add_to_digest_map(): Added channel 0x20960680 (global ID 8) to identity map in state opening (1) with digest E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F Aug 16 09:36:49.000 [info] channel_tls_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good. Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:49.000 [debug] channel_change_state(): Changing state of channel 0x20960680 (global ID 8) from "opening" to "open" Aug 16 09:36:49.000 [debug] circuit_n_chan_done(): chan to NULL/46.165.223.227:443, status=1 Aug 16 09:36:49.000 [info] channel_tls_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 4. Its ID digest is E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F. Our address is apparently 68.81.151.17. Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:49.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:49.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:49.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:36:49.000 [debug] connection_read_to_buf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:36:49.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:36:49.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20960680 (global ID 8) Aug 16 09:36:49.000 [debug] command_process_create_cell(): Got a CREATE cell for circ_id 2147485869 on channel 8 (0x20960680) Aug 16 09:36:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found nothing for circ_id 2147485869, channel ID 8 (0x20960680) Aug 16 09:36:49.000 [debug] circuitmux_attach_circuit(): Attaching circuit 2147485869 on channel 8 to cmux 0x235e8740 Aug 16 09:36:49.000 [warn] Couldn't construct socketpair for cpuworker: Bad address Aug 16 09:36:49.000 [warn] Cpuworker spawn failed. Will try again later. Aug 16 09:36:49.000 [debug] assign_onionskin_to_cpuworker(): No idle cpuworkers. Queuing. Aug 16 09:36:49.000 [info] onion_pending_add(): New create (ntor). Queues now ntor=1 and tap=0. Aug 16 09:36:49.000 [debug] command_process_create_cell(): success: handed off onionskin. Aug 16 09:36:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:36:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:50.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:36:50.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:36:50.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:36:50.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:51.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:52.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:52.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:53.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:53.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:54.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:54.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:55.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:55.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:56.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:56.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:56.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:57.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:57.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:57.000 [info] Monitored process 4046 is still alive. Aug 16 09:36:58.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:58.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:36:59.000 [info] update_consensus_router_descriptor_downloads(): 1 router descriptors downloadable. 0 delayed; 6054 present (0 of those were in old_routers); 0 would_reject; 0 wouldnt_use; 0 in progress. Aug 16 09:36:59.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:36:59.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:00.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:00.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:01.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:01.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:02.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:02.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:03.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:03.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:04.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:04.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:05.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:05.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:06.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:06.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:07.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:07.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:08.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:08.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:09.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:09.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:10.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:10.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:11.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:11.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:12.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:12.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:12.000 [info] Monitored process 4046 is still alive. Aug 16 09:37:13.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:13.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:14.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:14.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:15.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:15.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:16.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:16.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:17.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:17.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:18.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:18.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:19.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:19.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:20.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:20.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:21.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:21.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:22.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:22.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:23.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:23.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:24.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:24.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:25.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:25.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:26.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:26.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:27.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:27.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:27.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:27.000 [info] Monitored process 4046 is still alive. Aug 16 09:37:28.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:28.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:29.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:29.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:30.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:30.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:31.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:31.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:32.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:32.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:33.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:33.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:34.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:34.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:35.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:35.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:36.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:36.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:37.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:37.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:38.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:38.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:39.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:39.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:40.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:40.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:41.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:41.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:42.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:42.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:42.000 [info] Monitored process 4046 is still alive. Aug 16 09:37:43.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:43.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:44.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:44.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:45.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:45.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:46.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:46.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 30 (62.210.82.177:443) [idle 180]. Aug 16 09:37:46.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1187 Aug 16 09:37:46.000 [debug] channel_close_from_lower_layer(): Closing channel 0x20950fe0 (global ID 7) due to lower-layer event Aug 16 09:37:46.000 [debug] channel_change_state(): Changing state of channel 0x20950fe0 (global ID 7) from "open" to "closing" Aug 16 09:37:46.000 [debug] channel_remove_from_digest_map(): Removed channel 0x20950fe0 (global ID 7) from identity map in state closing (4) with digest 7663AD93B561AA11F40982BBDB3D3063AD28E3C7 Aug 16 09:37:46.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 30). Aug 16 09:37:46.000 [debug] channel_change_state(): Changing state of channel 0x20950fe0 (global ID 7) from "closing" to "closed" Aug 16 09:37:46.000 [debug] connection_remove(): removing socket 30 (type OR), n_conns now 9 Aug 16 09:37:46.000 [debug] connection_free_(): closing fd 30. Aug 16 09:37:46.000 [debug] channel_free(): Freeing channel 7 at 0x20950fe0 Aug 16 09:37:46.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x20950fe0 with global ID 7 Aug 16 09:37:46.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:47.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:47.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:48.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:49.000 [debug] resolve_my_address(): Guessed local host name as 'MAINMACHINE' Aug 16 09:37:49.000 [info] resolve_my_address(): Guessed local hostname 'MAINMACHINE' resolves to a private IP address (192.168.0.2). Trying something else. Aug 16 09:37:49.000 [info] resolve_my_address(): Could not get local interface IP address. Too bad. Aug 16 09:37:49.000 [info] resolve_my_address(): Address 'MAINMACHINE' resolves to private IP address '192.168.0.2'. Tor servers that use the default DirAuthorities must have public IP addresses. Aug 16 09:37:49.000 [info] check_descriptor_ipaddress_changed(): options->Address didn't resolve into an IP. Aug 16 09:37:49.000 [info] consider_testing_reachability(): Testing reachability of my ORPort: 68.81.151.17:9001. Aug 16 09:37:49.000 [debug] new_route_len(): Chosen route length 3 (6053/6055 routers suitable). Aug 16 09:37:49.000 [info] onion_pick_cpath_exit(): Using requested exit node '$B87C11E2ECB617289BA4F24EFAB85C339232ED38~Brrraaaap at 68.81.151.17' Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Path is 0 long; we want 3 Aug 16 09:37:49.000 [debug] extend_info_from_node(): using 178.254.55.101:9901 for mbTorServerNode Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Chose router $E18E0924B390CA10E0402D565BFC595B7678ABBB~mbTorServerNode at 178.254.55.101 for hop 1 (exit is Brrraaaap) Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Path is 1 long; we want 3 Aug 16 09:37:49.000 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice. Aug 16 09:37:49.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as middle node based on weights Wg=0.429200 Wm=1.000000 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:37:49.000 [debug] extend_info_from_node(): using 95.211.169.35:443 for MysticOrb Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Chose router $7F1D228E17AA6F4CEC24A90082CB2D457013C994~MysticOrb at 95.211.169.35 for hop 2 (exit is Brrraaaap) Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Path is 2 long; we want 3 Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Chose router $B87C11E2ECB617289BA4F24EFAB85C339232ED38~Brrraaaap at 68.81.151.17 for hop 3 (exit is Brrraaaap) Aug 16 09:37:49.000 [debug] onion_extend_cpath(): Path is complete: 3 steps long Aug 16 09:37:49.000 [debug] circuit_handle_first_hop(): Looking for firsthop '178.254.55.101:9901' Aug 16 09:37:49.000 [debug] circuit_handle_first_hop(): Conn open. Delivering first onion skin. Aug 16 09:37:49.000 [debug] circuit_send_next_onion_skin(): First skin; sending create cell. Aug 16 09:37:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found nothing for circ_id 2147500131, channel ID 0 (0x20fb1c00) Aug 16 09:37:49.000 [debug] circuit_deliver_create_cell(): Chosen circID 2147500131. Aug 16 09:37:49.000 [debug] circuitmux_attach_circuit(): Attaching circuit 2147500131 on channel 0 to cmux 0x218a6060 Aug 16 09:37:49.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:37:49.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:37:49.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:37:49.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:37:49.000 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to '$E18E0924B390CA10E0402D565BFC595B7678ABBB~mbTorServerNode at 178.254.55.101' Aug 16 09:37:49.000 [info] routerlist_remove_old_routers(): We have 6054 live routers and 2809 old router descriptors. Aug 16 09:37:49.000 [info] circuit_expire_building(): Abandoning circ 13 5.135.59.74:80:-2147481363 (state 0,0:doing handshakes, purpose 18, len 3) Aug 16 09:37:49.000 [info] internal circ (length 3, last hop Brrraaaap): $704386F528CD7C31F8A46664A543A8A1513C949D(open) $E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(waiting for keys) Aug 16 09:37:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x2093be80 for circ_id 2147485933, channel ID 1 (0x21983820) Aug 16 09:37:49.000 [info] circuit_testing_failed(): Our testing circuit (to see if your ORPort is reachable) has failed. I'll try again later. Aug 16 09:37:49.000 [debug] channel_send_destroy(): Sending destroy (circID 2147485933) on channel 0x21983820 (global ID 1) Aug 16 09:37:49.000 [debug] channel_write_cell(): Writing cell_t 0xb1f9c8 to channel 0x21983820 with global ID 1 Aug 16 09:37:49.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:37:49.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:37:49.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 24 wants to write. Aug 16 09:37:49.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:37:49.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:37:49.000 [debug] conn_read_callback(): socket 21 wants to read. Aug 16 09:37:49.000 [debug] connection_read_to_buf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:37:49.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:37:49.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:37:49.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20fb1c00 (global ID 0) Aug 16 09:37:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x204eb400 for circ_id 2147500131, channel ID 0 (0x20fb1c00) Aug 16 09:37:49.000 [debug] command_process_created_cell(): at OP. Finishing handshake. Aug 16 09:37:49.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:37:49.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $7F1D228E17AA6F4CEC24A90082CB2D457013C994(closed) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:37:49.000 [debug] command_process_created_cell(): Moving to next skin. Aug 16 09:37:49.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:37:49.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:37:49.000 [debug] relay_send_command_from_edge_(): delivering 14 cell forward. Aug 16 09:37:49.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 7 remaining. Aug 16 09:37:49.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:37:49.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:37:49.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:37:49.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:37:49.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:37:49.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:37:49.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:37:49.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:49.000 [debug] conn_read_callback(): socket 27 wants to read. Aug 16 09:37:49.000 [debug] connection_read_to_buf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:37:49.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:37:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:37:49.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20960680 (global ID 8) Aug 16 09:37:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x20953680 for circ_id 2147485869, channel ID 8 (0x20960680) Aug 16 09:37:49.000 [debug] command_process_destroy_cell(): Received for circID 2147485869. Aug 16 09:37:49.000 [debug] connection_or_process_cells_from_inbuf(): 27: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:37:49.000 [debug] conn_read_callback(): socket 21 wants to read. Aug 16 09:37:49.000 [debug] connection_read_to_buf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:37:49.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:37:49.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:37:49.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20fb1c00 (global ID 0) Aug 16 09:37:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x204eb400 for circ_id 2147500131, channel ID 0 (0x20fb1c00) Aug 16 09:37:49.000 [debug] circuit_receive_relay_cell(): Sending to origin. Aug 16 09:37:49.000 [debug] connection_edge_process_relay_cell(): Now seen 4145 relay cells here (command 15, stream 0). Aug 16 09:37:49.000 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Aug 16 09:37:49.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:37:49.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $7F1D228E17AA6F4CEC24A90082CB2D457013C994(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:37:49.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:37:49.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:37:49.000 [debug] relay_send_command_from_edge_(): delivering 14 cell forward. Aug 16 09:37:49.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 6 remaining. Aug 16 09:37:49.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:37:49.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:37:49.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:37:49.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:37:49.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:37:49.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:37:49.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:37:49.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:37:49.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:37:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:37:49.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:37:50.000 [debug] conn_read_callback(): socket 17 wants to read. Aug 16 09:37:50.000 [debug] connection_handle_listener_read(): Connection accepted on socket 28 (child of fd 17). Aug 16 09:37:50.000 [debug] connection_add_impl(): new conn type OR, socket 28, address 95.211.169.35, n_conns 9. Aug 16 09:37:50.000 [debug] channel_register(): Registering channel 0x2094f6c0 (ID 9) in state opening (1) with digest 0000000000000000000000000000000000000000 Aug 16 09:37:50.000 [info] channel_register(): Channel 0x2094f6c0 (global ID 9) in state opening (1) registered with no identity digest Aug 16 09:37:50.000 [debug] channel_listener_queue_incoming(): Queueing incoming channel 0x2094f6c0 (global ID 9) on channel listener 0x2093be20 (global ID 3) Aug 16 09:37:50.000 [debug] channel_set_cell_handlers(): Setting cell_handler callback for channel 0x2094f6c0 to 0x1676c5 Aug 16 09:37:50.000 [debug] channel_set_cell_handlers(): Setting var_cell_handler callback for channel 0x2094f6c0 to 0x166d8e Aug 16 09:37:50.000 [debug] connection_tls_start_handshake(): starting TLS handshake on fd 28 Aug 16 09:37:50.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x204eb300 (before/accept initialization) Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state before/accept initialization [type=16,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state before/accept initialization [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv2/v3 read client hello A [type=8194,val=-1]. Aug 16 09:37:50.000 [debug] tor_tls_handshake(): After call, 0x204eb300 was in state SSLv2/v3 read client hello A Aug 16 09:37:50.000 [debug] connection_tls_continue_handshake(): wanted read Aug 16 09:37:50.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:37:50.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x204eb300 (SSLv2/v3 read client hello A) Aug 16 09:37:50.000 [debug] tor_tls_classify_client_ciphers(): Got a non-version-1 cipher called 'ECDHE-ECDSA-AES128-GCM-SHA256' Aug 16 09:37:50.000 [debug] tor_tls_classify_client_ciphers(): Got a real V2/V3 cipher list from [scrubbed]. It is: 'ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:ECDHE-RSA-AES256-SHA:ECDHE-RSA-DES-CBC3-SHA:ECDHE-ECDSA-RC4-SHA:ECDHE-RSA-RC4-SHA:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA:DHE-RSA-CAMELLIA128-SHA:DHE-RSA-AES256-SHA:DHE-DSS-AES256-SHA:DHE-RSA-CAMELLIA256-SHA:EDH-RSA-DES-CBC3-SHA:AES128-SHA:CAMELLIA128-SHA:AES256-SHA:CAMELLIA256-SHA:DES-CBC3-SHA:RC4-SHA:RC4-MD5' Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 read client hello A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 write server hello A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 write certificate A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 write key exchange A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 write server done A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 flush data [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 read client certificate A [type=8194,val=-1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 read client certificate A [type=8194,val=-1]. Aug 16 09:37:50.000 [debug] tor_tls_handshake(): After call, 0x204eb300 was in state SSLv3 read client certificate A Aug 16 09:37:50.000 [debug] connection_tls_continue_handshake(): wanted read Aug 16 09:37:50.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:37:50.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x204eb300 (SSLv3 read client certificate A) Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 read client key exchange A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 read finished A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 write change cipher spec A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 write finished A [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSLv3 flush data [type=8193,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSL negotiation finished successfully [type=32,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_debug_state_callback(): SSL 0x235e8820 is now in state SSL negotiation finished successfully [type=8194,val=1]. Aug 16 09:37:50.000 [debug] tor_tls_handshake(): After call, 0x204eb300 was in state SSL negotiation finished successfully Aug 16 09:37:50.000 [debug] tor_tls_finish_handshake(): Completed V2 TLS handshake with client; waiting for renegotiation. Aug 16 09:37:50.000 [debug] connection_tls_continue_handshake(): Done with initial SSL handshake (server-side). Expecting renegotiation or VERSIONS cell Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:50.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:37:50.000 [debug] connection_read_to_buf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:37:50.000 [debug] connection_read_to_buf(): After TLS read of 9: 392 read, 801 written Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 9 (0 pending in tls object). Aug 16 09:37:50.000 [info] channel_tls_process_versions_cell(): Negotiated version 4 with [scrubbed]:7990; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:50.000 [debug] conn_write_callback(): socket 28 wants to write. Aug 16 09:37:50.000 [debug] flush_chunk_tls(): flushed 1467 bytes, 0 ready to flush, 0 remain. Aug 16 09:37:50.000 [debug] connection_handle_write_impl(): After TLS write of 1467: 0 read, 1496 written Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:37:50.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:37:50.000 [debug] connection_read_to_buf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:37:50.000 [debug] connection_read_to_buf(): After TLS read of 1781: 1810 read, 0 written Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 1781 (0 pending in tls object). Aug 16 09:37:50.000 [info] channel_tls_process_certs_cell(): Got some good certificates from [scrubbed]:7990: Waiting for AUTHENTICATE. Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 877 (0 pending in tls object). Aug 16 09:37:50.000 [debug] channel_set_identity_digest(): Setting remote endpoint digest on channel 0x2094f6c0 with global ID 9 to digest 7F1D228E17AA6F4CEC24A90082CB2D457013C994 Aug 16 09:37:50.000 [debug] channel_add_to_digest_map(): Added channel 0x2094f6c0 (global ID 9) to identity map in state opening (1) with digest 7F1D228E17AA6F4CEC24A90082CB2D457013C994 Aug 16 09:37:50.000 [info] channel_tls_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:443: Looks good. Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:37:50.000 [debug] channel_change_state(): Changing state of channel 0x2094f6c0 (global ID 9) from "opening" to "open" Aug 16 09:37:50.000 [debug] circuit_n_chan_done(): chan to NULL/95.211.169.35:443, status=1 Aug 16 09:37:50.000 [info] channel_tls_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:443; OR connection is now open, using protocol version 4. Its ID digest is 7F1D228E17AA6F4CEC24A90082CB2D457013C994. Our address is apparently 68.81.151.17. Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:37:50.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:50.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:37:50.000 [debug] connection_read_to_buf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:37:50.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:37:50.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x2094f6c0 (global ID 9) Aug 16 09:37:50.000 [debug] command_process_create_cell(): Got a CREATE cell for circ_id 2147488107 on channel 9 (0x2094f6c0) Aug 16 09:37:50.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found nothing for circ_id 2147488107, channel ID 9 (0x2094f6c0) Aug 16 09:37:50.000 [debug] circuitmux_attach_circuit(): Attaching circuit 2147488107 on channel 9 to cmux 0x235e37c0 Aug 16 09:37:50.000 [warn] Couldn't construct socketpair for cpuworker: Bad address Aug 16 09:37:50.000 [warn] Cpuworker spawn failed. Will try again later. Aug 16 09:37:50.000 [debug] assign_onionskin_to_cpuworker(): No idle cpuworkers. Queuing. Aug 16 09:37:50.000 [info] onion_pending_add(): New create (ntor). Queues now ntor=1 and tap=0. Aug 16 09:37:50.000 [debug] command_process_create_cell(): success: handed off onionskin. Aug 16 09:37:50.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:37:50.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:37:51.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:52.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:52.000 [debug] run_connection_housekeeping(): Sending keepalive to (195.169.125.226:9001) Aug 16 09:37:52.000 [debug] conn_write_callback(): socket 25 wants to write. Aug 16 09:37:52.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:37:52.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:37:52.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:52.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:37:52.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:37:52.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:37:52.000 [debug] conn_read_callback(): socket 25 wants to read. Aug 16 09:37:52.000 [debug] connection_read_to_buf(): 25: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:37:52.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:37:52.000 [debug] connection_or_process_cells_from_inbuf(): 25: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:37:52.000 [debug] connection_or_process_cells_from_inbuf(): 25: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:37:52.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:37:52.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:37:52.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:37:53.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:53.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:54.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:54.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:55.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:55.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:56.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:56.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:57.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:57.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:57.000 [info] Monitored process 4046 is still alive. Aug 16 09:37:58.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:58.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:58.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:37:59.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:37:59.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:00.000 [info] update_consensus_router_descriptor_downloads(): 1 router descriptors downloadable. 0 delayed; 6054 present (0 of those were in old_routers); 0 would_reject; 0 wouldnt_use; 0 in progress. Aug 16 09:38:00.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:00.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:01.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:01.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:02.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:02.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:03.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:03.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:04.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:04.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:05.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:05.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:06.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:06.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:07.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:07.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:08.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:08.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:09.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:09.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:10.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:10.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:11.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:11.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:12.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:12.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:12.000 [info] Monitored process 4046 is still alive. Aug 16 09:38:13.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:13.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:14.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:14.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:15.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:15.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:16.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:16.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:17.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:17.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:18.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:18.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:19.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:19.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:20.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:20.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:21.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:21.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:22.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:22.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:23.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:23.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:24.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:24.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:25.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:25.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:26.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:26.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:27.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:27.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:27.000 [info] Monitored process 4046 is still alive. Aug 16 09:38:28.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:28.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:29.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:29.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:29.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:30.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:30.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:31.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:31.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:32.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:32.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:33.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:33.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:34.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:34.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:35.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:35.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:36.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:36.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:37.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:37.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:38.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:38.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:39.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:39.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:40.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:40.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:41.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:41.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:42.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:42.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:42.000 [info] Monitored process 4046 is still alive. Aug 16 09:38:43.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:43.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:44.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:44.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:45.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:45.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:46.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:46.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:47.000 [debug] count_usable_descriptors(): 6049 usable, 6048 present (descs). Aug 16 09:38:47.000 [debug] count_usable_descriptors(): 1127 usable, 1126 present (desc exits). Aug 16 09:38:47.000 [debug] count_usable_descriptors(): 1127 usable, 1126 present (desc exits). Aug 16 09:38:47.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as guard based on weights Wg=0.570800 Wm=0.570800 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:38:47.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as middle node based on weights Wg=0.429200 Wm=1.000000 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:38:47.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as exit based on weights Wg=0.843900 Wm=1.000000 We=1.000000 Wd=0.843900 with total bw 0 Aug 16 09:38:47.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as exit based on weights Wg=0.843900 Wm=1.000000 We=1.000000 Wd=0.843900 with total bw 0 Aug 16 09:38:47.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:47.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:48.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:49.000 [info] circuit_expire_building(): Abandoning circ 14 178.254.55.101:9901:-2147467165 (state 0,0:doing handshakes, purpose 18, len 3) Aug 16 09:38:49.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $7F1D228E17AA6F4CEC24A90082CB2D457013C994(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(waiting for keys) Aug 16 09:38:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x204eb400 for circ_id 2147500131, channel ID 0 (0x20fb1c00) Aug 16 09:38:49.000 [info] circuit_testing_failed(): Our testing circuit (to see if your ORPort is reachable) has failed. I'll try again later. Aug 16 09:38:49.000 [debug] channel_send_destroy(): Sending destroy (circID 2147500131) on channel 0x20fb1c00 (global ID 0) Aug 16 09:38:49.000 [debug] channel_write_cell(): Writing cell_t 0xb1f9c8 to channel 0x20fb1c00 with global ID 0 Aug 16 09:38:49.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:49.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:38:49.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:38:49.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:38:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:49.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:38:49.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:38:49.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:38:49.000 [debug] conn_read_callback(): socket 28 wants to read. Aug 16 09:38:49.000 [debug] connection_read_to_buf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:38:49.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:38:49.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:38:49.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x2094f6c0 (global ID 9) Aug 16 09:38:49.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x20953680 for circ_id 2147488107, channel ID 9 (0x2094f6c0) Aug 16 09:38:49.000 [debug] command_process_destroy_cell(): Received for circID 2147488107. Aug 16 09:38:49.000 [debug] connection_or_process_cells_from_inbuf(): 28: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:49.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:38:49.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:38:49.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:38:50.000 [debug] resolve_my_address(): Guessed local host name as 'MAINMACHINE' Aug 16 09:38:50.000 [info] resolve_my_address(): Guessed local hostname 'MAINMACHINE' resolves to a private IP address (192.168.0.2). Trying something else. Aug 16 09:38:50.000 [info] resolve_my_address(): Could not get local interface IP address. Too bad. Aug 16 09:38:50.000 [info] resolve_my_address(): Address 'MAINMACHINE' resolves to private IP address '192.168.0.2'. Tor servers that use the default DirAuthorities must have public IP addresses. Aug 16 09:38:50.000 [info] check_descriptor_ipaddress_changed(): options->Address didn't resolve into an IP. Aug 16 09:38:50.000 [info] consider_testing_reachability(): Testing reachability of my ORPort: 68.81.151.17:9001. Aug 16 09:38:50.000 [debug] new_route_len(): Chosen route length 3 (6053/6055 routers suitable). Aug 16 09:38:50.000 [info] onion_pick_cpath_exit(): Using requested exit node '$B87C11E2ECB617289BA4F24EFAB85C339232ED38~Brrraaaap at 68.81.151.17' Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Path is 0 long; we want 3 Aug 16 09:38:50.000 [debug] extend_info_from_node(): using 178.254.55.101:9901 for mbTorServerNode Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Chose router $E18E0924B390CA10E0402D565BFC595B7678ABBB~mbTorServerNode at 178.254.55.101 for hop 1 (exit is Brrraaaap) Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Path is 1 long; we want 3 Aug 16 09:38:50.000 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice. Aug 16 09:38:50.000 [debug] compute_weighted_bandwidths(): Generated weighted bandwidths for rule weight as middle node based on weights Wg=0.429200 Wm=1.000000 We=0.000000 Wd=0.078000 with total bw 0 Aug 16 09:38:50.000 [debug] extend_info_from_node(): using 192.99.6.32:8081 for hamsternator Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Chose router $753973FCFFC0724FF79DB1AA0166B0B585B7D4F2~hamsternator at 192.99.6.32 for hop 2 (exit is Brrraaaap) Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Path is 2 long; we want 3 Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Chose router $B87C11E2ECB617289BA4F24EFAB85C339232ED38~Brrraaaap at 68.81.151.17 for hop 3 (exit is Brrraaaap) Aug 16 09:38:50.000 [debug] onion_extend_cpath(): Path is complete: 3 steps long Aug 16 09:38:50.000 [debug] circuit_handle_first_hop(): Looking for firsthop '178.254.55.101:9901' Aug 16 09:38:50.000 [debug] circuit_handle_first_hop(): Conn open. Delivering first onion skin. Aug 16 09:38:50.000 [debug] circuit_send_next_onion_skin(): First skin; sending create cell. Aug 16 09:38:50.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found nothing for circ_id 2147500132, channel ID 0 (0x20fb1c00) Aug 16 09:38:50.000 [debug] circuit_deliver_create_cell(): Chosen circID 2147500132. Aug 16 09:38:50.000 [debug] circuitmux_attach_circuit(): Attaching circuit 2147500132 on channel 0 to cmux 0x218a6060 Aug 16 09:38:50.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:38:50.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:38:50.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:38:50.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:38:50.000 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to '$E18E0924B390CA10E0402D565BFC595B7678ABBB~mbTorServerNode at 178.254.55.101' Aug 16 09:38:50.000 [info] routerlist_remove_old_routers(): We have 6054 live routers and 2809 old router descriptors. Aug 16 09:38:50.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:50.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:38:50.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:38:50.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:38:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:50.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:38:50.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:38:50.000 [debug] conn_read_callback(): socket 21 wants to read. Aug 16 09:38:50.000 [debug] connection_read_to_buf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:38:50.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:38:50.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:38:50.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20fb1c00 (global ID 0) Aug 16 09:38:50.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x2093aa20 for circ_id 2147500132, channel ID 0 (0x20fb1c00) Aug 16 09:38:50.000 [debug] command_process_created_cell(): at OP. Finishing handshake. Aug 16 09:38:50.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:38:50.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $753973FCFFC0724FF79DB1AA0166B0B585B7D4F2(closed) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:38:50.000 [debug] command_process_created_cell(): Moving to next skin. Aug 16 09:38:50.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:38:50.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:38:50.000 [debug] relay_send_command_from_edge_(): delivering 6 cell forward. Aug 16 09:38:50.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 6 remaining. Aug 16 09:38:50.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:38:50.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:38:50.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:38:50.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:38:50.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:38:50.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:50.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:38:50.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:38:50.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:38:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:50.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:38:50.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:38:50.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:38:50.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 21 wants to read. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): After TLS read of 514: 543 read, 0 written Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 514 (0 pending in tls object). Aug 16 09:38:51.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x20fb1c00 (global ID 0) Aug 16 09:38:51.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x2093aa20 for circ_id 2147500132, channel ID 0 (0x20fb1c00) Aug 16 09:38:51.000 [debug] circuit_receive_relay_cell(): Sending to origin. Aug 16 09:38:51.000 [debug] connection_edge_process_relay_cell(): Now seen 4146 relay cells here (command 7, stream 0). Aug 16 09:38:51.000 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Aug 16 09:38:51.000 [info] circuit_finish_handshake(): Finished building circuit hop: Aug 16 09:38:51.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $753973FCFFC0724FF79DB1AA0166B0B585B7D4F2(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(closed) Aug 16 09:38:51.000 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Aug 16 09:38:51.000 [info] circuit_send_next_onion_skin(): Sending extend relay cell. Aug 16 09:38:51.000 [debug] relay_send_command_from_edge_(): delivering 6 cell forward. Aug 16 09:38:51.000 [debug] relay_send_command_from_edge_(): Sending a RELAY_EARLY cell; 5 remaining. Aug 16 09:38:51.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:38:51.000 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Aug 16 09:38:51.000 [debug] append_cell_to_circuit_queue(): Made a circuit active. Aug 16 09:38:51.000 [debug] append_cell_to_circuit_queue(): Primed a buffer. Aug 16 09:38:51.000 [debug] channel_write_packed_cell(): Writing packed_cell_t 0x22c00068 to channel 0x20fb1c00 with global ID 0 Aug 16 09:38:51.000 [debug] channel_flush_from_first_active_circuit(): Made a circuit inactive. Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 21: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:51.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:38:51.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:38:51.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:38:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:51.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:38:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 17 wants to read. Aug 16 09:38:51.000 [debug] connection_handle_listener_read(): Connection accepted on socket 29 (child of fd 17). Aug 16 09:38:51.000 [debug] connection_add_impl(): new conn type OR, socket 29, address 192.99.6.32, n_conns 10. Aug 16 09:38:51.000 [debug] channel_register(): Registering channel 0x2094fb00 (ID 10) in state opening (1) with digest 0000000000000000000000000000000000000000 Aug 16 09:38:51.000 [info] channel_register(): Channel 0x2094fb00 (global ID 10) in state opening (1) registered with no identity digest Aug 16 09:38:51.000 [debug] channel_listener_queue_incoming(): Queueing incoming channel 0x2094fb00 (global ID 10) on channel listener 0x2093be20 (global ID 3) Aug 16 09:38:51.000 [debug] channel_set_cell_handlers(): Setting cell_handler callback for channel 0x2094fb00 to 0x1676c5 Aug 16 09:38:51.000 [debug] channel_set_cell_handlers(): Setting var_cell_handler callback for channel 0x2094fb00 to 0x166d8e Aug 16 09:38:51.000 [debug] connection_tls_start_handshake(): starting TLS handshake on fd 29 Aug 16 09:38:51.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x204eb640 (before/accept initialization) Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state before/accept initialization [type=16,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state before/accept initialization [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv2/v3 read client hello A [type=8194,val=-1]. Aug 16 09:38:51.000 [debug] tor_tls_handshake(): After call, 0x204eb640 was in state SSLv2/v3 read client hello A Aug 16 09:38:51.000 [debug] connection_tls_continue_handshake(): wanted read Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:38:51.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x204eb640 (SSLv2/v3 read client hello A) Aug 16 09:38:51.000 [debug] tor_tls_classify_client_ciphers(): Got a non-version-1 cipher called 'ECDHE-ECDSA-AES256-SHA' Aug 16 09:38:51.000 [debug] tor_tls_classify_client_ciphers(): Got a real V2/V3 cipher list from [scrubbed]. It is: 'ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-CAMELLIA256-SHA:DHE-DSS-CAMELLIA256-SHA:DHE-RSA-AES256-SHA:DHE-DSS-AES256-SHA:ECDH-RSA-AES256-SHA:ECDH-ECDSA-AES256-SHA:CAMELLIA256-SHA:AES256-SHA:ECDHE-ECDSA-RC4-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-RC4-SHA:ECDHE-RSA-AES128-SHA:DHE-RSA-CAMELLIA128-SHA:DHE-DSS-CAMELLIA128-SHA:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA:ECDH-RSA-RC4-SHA:ECDH-RSA-AES128-SHA:ECDH-ECDSA-RC4-SHA:ECDH-ECDSA-AES128-SHA:SEED-SHA:CAMELLIA128-SHA:RC4-MD5:RC4-SHA:AES128-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:EDH-DSS-DES-CBC3-SHA:ECDH-RSA-DES-CBC3-SHA:ECDH-ECDSA-DES-CBC3-SHA:DES-CBC3-SHA' Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 read client hello A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 write server hello A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 write certificate A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 write key exchange A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 write server done A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 flush data [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 read client certificate A [type=8194,val=-1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 read client certificate A [type=8194,val=-1]. Aug 16 09:38:51.000 [debug] tor_tls_handshake(): After call, 0x204eb640 was in state SSLv3 read client certificate A Aug 16 09:38:51.000 [debug] connection_tls_continue_handshake(): wanted read Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:38:51.000 [debug] tor_tls_handshake(): About to call SSL_accept on 0x204eb640 (SSLv3 read client certificate A) Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 read client key exchange A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 read finished A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 write change cipher spec A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 write finished A [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSLv3 flush data [type=8193,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSL negotiation finished successfully [type=32,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_debug_state_callback(): SSL 0x204ee240 is now in state SSL negotiation finished successfully [type=8194,val=1]. Aug 16 09:38:51.000 [debug] tor_tls_handshake(): After call, 0x204eb640 was in state SSL negotiation finished successfully Aug 16 09:38:51.000 [debug] tor_tls_finish_handshake(): Completed V2 TLS handshake with client; waiting for renegotiation. Aug 16 09:38:51.000 [debug] connection_tls_continue_handshake(): Done with initial SSL handshake (server-side). Expecting renegotiation or VERSIONS cell Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): After TLS read of 7: 422 read, 807 written Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 7 (0 pending in tls object). Aug 16 09:38:51.000 [info] channel_tls_process_versions_cell(): Negotiated version 3 with [scrubbed]:60143; Sending cells: VERSIONS CERTS AUTH_CHALLENGE NETINFO Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:51.000 [debug] conn_write_callback(): socket 29 wants to write. Aug 16 09:38:51.000 [debug] flush_chunk_tls(): flushed 1461 bytes, 0 ready to flush, 0 remain. Aug 16 09:38:51.000 [debug] connection_handle_write_impl(): After TLS write of 1461: 0 read, 1530 written Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:38:51.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:38:51.000 [debug] tor_tls_read(): read returned r=-1, err=-2 Aug 16 09:38:51.000 [debug] connection_read_to_buf(): After TLS read of 0: 1448 read, 0 written Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): After TLS read of 1786: 402 read, 0 written Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 1786 (0 pending in tls object). Aug 16 09:38:51.000 [info] channel_tls_process_certs_cell(): Got some good certificates from [scrubbed]:60143: Waiting for AUTHENTICATE. Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 873 (0 pending in tls object). Aug 16 09:38:51.000 [debug] channel_set_identity_digest(): Setting remote endpoint digest on channel 0x2094fb00 with global ID 10 to digest 753973FCFFC0724FF79DB1AA0166B0B585B7D4F2 Aug 16 09:38:51.000 [debug] channel_add_to_digest_map(): Added channel 0x2094fb00 (global ID 10) to identity map in state opening (1) with digest 753973FCFFC0724FF79DB1AA0166B0B585B7D4F2 Aug 16 09:38:51.000 [info] channel_tls_process_authenticate_cell(): Got an AUTHENTICATE cell from [scrubbed]:8081: Looks good. Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 512 (0 pending in tls object). Aug 16 09:38:51.000 [debug] channel_change_state(): Changing state of channel 0x2094fb00 (global ID 10) from "opening" to "open" Aug 16 09:38:51.000 [debug] circuit_n_chan_done(): chan to NULL/192.99.6.32:8081, status=1 Aug 16 09:38:51.000 [info] channel_tls_process_netinfo_cell(): Got good NETINFO cell from [scrubbed]:8081; OR connection is now open, using protocol version 3. Its ID digest is 753973FCFFC0724FF79DB1AA0166B0B585B7D4F2. Our address is apparently 68.81.151.17. Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:38:51.000 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 512 (0 pending in tls object). Aug 16 09:38:51.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x2094fb00 (global ID 10) Aug 16 09:38:51.000 [debug] command_process_create_cell(): Got a CREATE cell for circ_id 17912 on channel 10 (0x2094fb00) Aug 16 09:38:51.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() found nothing for circ_id 17912, channel ID 10 (0x2094fb00) Aug 16 09:38:51.000 [debug] circuitmux_attach_circuit(): Attaching circuit 17912 on channel 10 to cmux 0x204eb600 Aug 16 09:38:51.000 [warn] Couldn't construct socketpair for cpuworker: Bad address Aug 16 09:38:51.000 [warn] Cpuworker spawn failed. Will try again later. Aug 16 09:38:51.000 [debug] assign_onionskin_to_cpuworker(): No idle cpuworkers. Queuing. Aug 16 09:38:51.000 [info] onion_pending_add(): New create (ntor). Queues now ntor=1 and tap=0. Aug 16 09:38:51.000 [debug] command_process_create_cell(): success: handed off onionskin. Aug 16 09:38:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:38:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:52.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:38:52.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:38:52.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:38:52.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:52.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:53.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:53.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:54.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:54.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:55.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:55.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:56.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:56.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:57.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:57.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:57.000 [info] Monitored process 4046 is still alive. Aug 16 09:38:58.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:58.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:38:59.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:38:59.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:00.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:00.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:00.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:01.000 [info] update_consensus_router_descriptor_downloads(): 1 router descriptors downloadable. 0 delayed; 6054 present (0 of those were in old_routers); 0 would_reject; 0 wouldnt_use; 0 in progress. Aug 16 09:39:01.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:01.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:02.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:02.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:03.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:03.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:04.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:04.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:05.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:05.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:06.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:06.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:07.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:07.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:08.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:08.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:09.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:09.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:10.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:10.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:11.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:11.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:12.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:12.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:12.000 [info] Monitored process 4046 is still alive. Aug 16 09:39:13.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:13.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:14.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:14.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:15.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:15.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:16.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:16.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:17.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:17.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:18.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:18.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:19.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:19.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:20.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:20.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:21.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:21.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:22.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:22.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:23.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:23.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:24.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:24.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:25.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:25.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:26.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:26.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:27.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:27.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:27.000 [info] Monitored process 4046 is still alive. Aug 16 09:39:28.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:28.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:29.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:29.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:30.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:30.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:31.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:31.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:31.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:32.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:32.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:33.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:33.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:34.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:34.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:35.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:35.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:36.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:36.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:37.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:37.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:38.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:38.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:39.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:39.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:40.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:40.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:41.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:41.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:42.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:42.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:42.000 [info] Monitored process 4046 is still alive. Aug 16 09:39:43.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:43.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:44.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:44.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:45.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:45.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:46.000 [debug] conn_read_callback(): socket 26 wants to read. Aug 16 09:39:46.000 [debug] read_to_chunk(): Read 16 bytes. 16 on inbuf. Aug 16 09:39:46.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:46.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:46.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:47.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:47.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:48.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:48.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:49.000 [debug] circuit_build_times_disabled(): CircuitBuildTime learning is not disabled. Consensus=0, Config=0, AuthDir=0, StateFile=0 Aug 16 09:39:49.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 27 (46.165.223.227:443) [idle 180]. Aug 16 09:39:49.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1187 Aug 16 09:39:49.000 [debug] channel_close_from_lower_layer(): Closing channel 0x20960680 (global ID 8) due to lower-layer event Aug 16 09:39:49.000 [debug] channel_change_state(): Changing state of channel 0x20960680 (global ID 8) from "open" to "closing" Aug 16 09:39:49.000 [debug] channel_remove_from_digest_map(): Removed channel 0x20960680 (global ID 8) from identity map in state closing (4) with digest E99B122BAAC1C009E7CE9F3DBBDA5E909A9F198F Aug 16 09:39:49.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 27). Aug 16 09:39:49.000 [debug] channel_change_state(): Changing state of channel 0x20960680 (global ID 8) from "closing" to "closed" Aug 16 09:39:49.000 [debug] connection_remove(): removing socket 27 (type OR), n_conns now 10 Aug 16 09:39:49.000 [debug] connection_free_(): closing fd 27. Aug 16 09:39:49.000 [debug] channel_free(): Freeing channel 8 at 0x20960680 Aug 16 09:39:49.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x20960680 with global ID 8 Aug 16 09:39:49.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:50.000 [debug] conn_read_callback(): socket 26 wants to read. Aug 16 09:39:50.000 [debug] read_to_chunk(): Read 17 bytes. 17 on inbuf. Aug 16 09:39:50.000 [notice] Interrupt: we have stopped accepting new connections, and will shut down in 30 seconds. Interrupt again to exit now. Aug 16 09:39:50.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 12). Aug 16 09:39:50.000 [debug] connection_remove(): removing socket 12 (type Socks listener), n_conns now 9 Aug 16 09:39:50.000 [debug] connection_free_(): closing fd 12. Aug 16 09:39:50.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 17). Aug 16 09:39:50.000 [debug] connection_remove(): removing socket 17 (type OR listener), n_conns now 8 Aug 16 09:39:50.000 [debug] connection_free_(): closing fd 17. Aug 16 09:39:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:50.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 28 (95.211.169.35:443) [Hibernating or exiting]. Aug 16 09:39:50.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1186 Aug 16 09:39:50.000 [debug] channel_close_from_lower_layer(): Closing channel 0x2094f6c0 (global ID 9) due to lower-layer event Aug 16 09:39:50.000 [debug] channel_change_state(): Changing state of channel 0x2094f6c0 (global ID 9) from "open" to "closing" Aug 16 09:39:50.000 [debug] channel_remove_from_digest_map(): Removed channel 0x2094f6c0 (global ID 9) from identity map in state closing (4) with digest 7F1D228E17AA6F4CEC24A90082CB2D457013C994 Aug 16 09:39:50.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 28). Aug 16 09:39:50.000 [debug] channel_change_state(): Changing state of channel 0x2094f6c0 (global ID 9) from "closing" to "closed" Aug 16 09:39:50.000 [debug] connection_remove(): removing socket 28 (type OR), n_conns now 7 Aug 16 09:39:50.000 [debug] connection_free_(): closing fd 28. Aug 16 09:39:50.000 [debug] pathbias_count_circs_in_states(): Found opened circuit 9 in path_state build succeeded Aug 16 09:39:50.000 [debug] pathbias_count_circs_in_states(): Found opened circuit 4 in path_state build succeeded Aug 16 09:39:50.000 [debug] pathbias_count_circs_in_states(): Found opened circuit 6 in path_state build succeeded Aug 16 09:39:50.000 [debug] pathbias_count_circs_in_states(): Found opened circuit 5 in path_state build succeeded Aug 16 09:39:50.000 [info] or_state_save(): Saved state to "C:/Home/Default/.tor/state" Aug 16 09:39:50.000 [debug] channel_free(): Freeing channel 9 at 0x2094f6c0 Aug 16 09:39:50.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x2094f6c0 with global ID 9 Aug 16 09:39:50.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:51.000 [debug] resolve_my_address(): Guessed local host name as 'MAINMACHINE' Aug 16 09:39:51.000 [info] resolve_my_address(): Guessed local hostname 'MAINMACHINE' resolves to a private IP address (192.168.0.2). Trying something else. Aug 16 09:39:51.000 [info] resolve_my_address(): Could not get local interface IP address. Too bad. Aug 16 09:39:51.000 [info] resolve_my_address(): Address 'MAINMACHINE' resolves to private IP address '192.168.0.2'. Tor servers that use the default DirAuthorities must have public IP addresses. Aug 16 09:39:51.000 [info] check_descriptor_ipaddress_changed(): options->Address didn't resolve into an IP. Aug 16 09:39:51.000 [info] routerlist_remove_old_routers(): We have 6054 live routers and 2809 old router descriptors. Aug 16 09:39:51.000 [info] circuit_expire_building(): Abandoning circ 15 178.254.55.101:9901:-2147467164 (state 0,0:doing handshakes, purpose 18, len 3) Aug 16 09:39:51.000 [info] internal circ (length 3, last hop Brrraaaap): $E18E0924B390CA10E0402D565BFC595B7678ABBB(open) $753973FCFFC0724FF79DB1AA0166B0B585B7D4F2(open) $B87C11E2ECB617289BA4F24EFAB85C339232ED38(waiting for keys) Aug 16 09:39:51.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x2093aa20 for circ_id 2147500132, channel ID 0 (0x20fb1c00) Aug 16 09:39:51.000 [info] circuit_testing_failed(): Our testing circuit (to see if your ORPort is reachable) has failed. I'll try again later. Aug 16 09:39:51.000 [debug] channel_send_destroy(): Sending destroy (circID 2147500132) on channel 0x20fb1c00 (global ID 0) Aug 16 09:39:51.000 [debug] channel_write_cell(): Writing cell_t 0xb1f9c8 to channel 0x20fb1c00 with global ID 0 Aug 16 09:39:51.000 [info] buf_shrink_freelists(): Cleaned freelist for 4096-byte chunks: original length 9, kept 8, dropped 1. Aug 16 09:39:51.000 [debug] conn_write_callback(): socket 21 wants to write. Aug 16 09:39:51.000 [debug] flush_chunk_tls(): flushed 514 bytes, 0 ready to flush, 0 remain. Aug 16 09:39:51.000 [debug] connection_handle_write_impl(): After TLS write of 514: 0 read, 543 written Aug 16 09:39:51.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:51.000 [debug] connection_bucket_refill_helper(): global_write_bucket now 1073741824. Aug 16 09:39:51.000 [debug] connection_bucket_refill_helper(): global_relayed_write_bucket now 393216. Aug 16 09:39:51.000 [debug] connection_bucket_refill_helper(): or_conn->write_bucket now 1073741824. Aug 16 09:39:51.000 [debug] conn_read_callback(): socket 29 wants to read. Aug 16 09:39:51.000 [debug] connection_read_to_buf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16384. Aug 16 09:39:51.000 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Aug 16 09:39:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 512 (0 pending in tls object). Aug 16 09:39:51.000 [debug] channel_queue_cell(): Directly handling incoming cell_t 0xb1f864 for channel 0x2094fb00 (global ID 10) Aug 16 09:39:51.000 [debug] circuit_get_by_circid_channel_impl(): circuit_get_by_circid_channel_impl() returning circuit 0x20965f20 for circ_id 17912, channel ID 10 (0x2094fb00) Aug 16 09:39:51.000 [debug] command_process_destroy_cell(): Received for circID 17912. Aug 16 09:39:51.000 [debug] connection_or_process_cells_from_inbuf(): 29: starting, inbuf_datalen 0 (0 pending in tls object). Aug 16 09:39:51.000 [debug] connection_bucket_refill_helper(): global_read_bucket now 1073741824. Aug 16 09:39:51.000 [debug] connection_bucket_refill_helper(): global_relayed_read_bucket now 393216. Aug 16 09:39:51.000 [debug] connection_bucket_refill_helper(): or_conn->read_bucket now 1073741824. Aug 16 09:39:52.000 [info] run_connection_housekeeping(): Expiring non-used OR connection to fd 29 (192.99.6.32:8081) [Hibernating or exiting]. Aug 16 09:39:52.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1186 Aug 16 09:39:52.000 [debug] channel_close_from_lower_layer(): Closing channel 0x2094fb00 (global ID 10) due to lower-layer event Aug 16 09:39:52.000 [debug] channel_change_state(): Changing state of channel 0x2094fb00 (global ID 10) from "open" to "closing" Aug 16 09:39:52.000 [debug] channel_remove_from_digest_map(): Removed channel 0x2094fb00 (global ID 10) from identity map in state closing (4) with digest 753973FCFFC0724FF79DB1AA0166B0B585B7D4F2 Aug 16 09:39:52.000 [debug] conn_close_if_marked(): Cleaning up connection (fd 29). Aug 16 09:39:52.000 [debug] channel_change_state(): Changing state of channel 0x2094fb00 (global ID 10) from "closing" to "closed" Aug 16 09:39:52.000 [debug] connection_remove(): removing socket 29 (type OR), n_conns now 6 Aug 16 09:39:52.000 [debug] connection_free_(): closing fd 29. Aug 16 09:39:52.000 [debug] channel_free(): Freeing channel 10 at 0x2094fb00 Aug 16 09:39:52.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x2094fb00 with global ID 10 Aug 16 09:39:52.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:53.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:54.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:55.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:56.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:57.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:57.000 [info] Monitored process 4046 is still alive. Aug 16 09:39:58.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:39:59.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:00.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:01.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:02.000 [info] update_consensus_router_descriptor_downloads(): 1 router descriptors downloadable. 0 delayed; 6054 present (0 of those were in old_routers); 0 would_reject; 0 wouldnt_use; 0 in progress. Aug 16 09:40:02.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:03.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:04.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:05.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:06.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:07.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:08.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:09.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:10.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:11.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:12.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:12.000 [info] Monitored process 4046 is still alive. Aug 16 09:40:13.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:14.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:15.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:16.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:17.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:18.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:18.000 [debug] conn_read_callback(): socket 26 wants to read. Aug 16 09:40:18.000 [debug] read_to_chunk(): Read 16 bytes. 16 on inbuf. Aug 16 09:40:18.000 [debug] conn_write_callback(): socket 26 wants to write. Aug 16 09:40:18.000 [debug] conn_read_callback(): socket 26 wants to read. Aug 16 09:40:18.000 [debug] read_to_chunk(): Read 17 bytes. 17 on inbuf. Aug 16 09:40:18.000 [notice] SIGINT received a second time; exiting now. Aug 16 09:40:18.000 [info] or_state_save(): Saved state to "C:/Home/Default/.tor/state" Aug 16 09:40:19.000 [debug] channel_tls_free_all(): Shutting down TLS channels... Aug 16 09:40:19.000 [debug] channel_tls_free_all(): Closing channel_tls_listener with ID 3 at 0x2093be20. Aug 16 09:40:19.000 [debug] channel_listener_mark_for_close(): Closing channel listener 0x2093be20 (global ID 3) by request Aug 16 09:40:19.000 [debug] channel_listener_change_state(): Changing state of channel listener 0x2093be20 (global ID 3from "listening" to "closing" Aug 16 09:40:19.000 [debug] channel_listener_change_state(): Changing state of channel listener 0x2093be20 (global ID 3from "closing" to "closed" Aug 16 09:40:19.000 [debug] channel_listener_free(): Freeing channel_listener_t 3 at 0x2093be20 Aug 16 09:40:19.000 [debug] channel_tls_free_all(): Done shutting down TLS channels Aug 16 09:40:19.000 [debug] channel_free_all(): Shutting down channels... Aug 16 09:40:19.000 [debug] channel_free_list(): Cleaning up channel 0x20fb1c00 (global ID 0) in state open (2) Aug 16 09:40:19.000 [debug] channel_remove_from_digest_map(): Removed channel 0x20fb1c00 (global ID 0) from identity map in state open (2) with digest E18E0924B390CA10E0402D565BFC595B7678ABBB Aug 16 09:40:19.000 [debug] channel_mark_for_close(): Closing channel 0x20fb1c00 (global ID 0) by request Aug 16 09:40:19.000 [debug] channel_change_state(): Changing state of channel 0x20fb1c00 (global ID 0) from "open" to "closing" Aug 16 09:40:19.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1186 Aug 16 09:40:19.000 [debug] channel_force_free(): Force-freeing channel 0 at 0x20fb1c00 Aug 16 09:40:19.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x20fb1c00 with global ID 0 Aug 16 09:40:19.000 [debug] channel_free_list(): Cleaning up channel 0x21983820 (global ID 1) in state open (2) Aug 16 09:40:19.000 [debug] channel_remove_from_digest_map(): Removed channel 0x21983820 (global ID 1) from identity map in state open (2) with digest 704386F528CD7C31F8A46664A543A8A1513C949D Aug 16 09:40:19.000 [debug] channel_mark_for_close(): Closing channel 0x21983820 (global ID 1) by request Aug 16 09:40:19.000 [debug] channel_change_state(): Changing state of channel 0x21983820 (global ID 1) from "open" to "closing" Aug 16 09:40:19.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1186 Aug 16 09:40:19.000 [debug] channel_force_free(): Force-freeing channel 1 at 0x21983820 Aug 16 09:40:19.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x21983820 with global ID 1 Aug 16 09:40:19.000 [debug] channel_free_list(): Cleaning up channel 0x21918460 (global ID 2) in state open (2) Aug 16 09:40:19.000 [debug] channel_remove_from_digest_map(): Removed channel 0x21918460 (global ID 2) from identity map in state open (2) with digest D7DB8E82604F806766FC3F80213CF719A0481D0B Aug 16 09:40:19.000 [debug] channel_mark_for_close(): Closing channel 0x21918460 (global ID 2) by request Aug 16 09:40:19.000 [debug] channel_change_state(): Changing state of channel 0x21918460 (global ID 2) from "open" to "closing" Aug 16 09:40:19.000 [debug] connection_mark_for_close_internal_(): Calling connection_mark_for_close_internal_() on an OR conn at src/or/connection_or.c:1186 Aug 16 09:40:19.000 [debug] channel_force_free(): Force-freeing channel 2 at 0x21918460 Aug 16 09:40:19.000 [debug] channel_clear_remote_end(): Clearing remote endpoint identity on channel 0x21918460 with global ID 2 Aug 16 09:40:19.000 [debug] channel_free_all(): Freeing channel_identity_map Aug 16 09:40:19.000 [debug] channel_free_all(): Done cleaning up after channels Aug 16 09:40:19.000 [debug] connection_free_(): closing fd 26. Aug 16 09:40:19.000 [debug] connection_free_(): closing fd 13. Aug 16 09:40:19.000 [debug] connection_free_(): closing fd 24. Aug 16 09:40:19.000 [debug] connection_free_(): closing fd 25. Aug 16 09:40:19.000 [debug] connection_free_(): closing fd 21. Aug 16 09:40:19.000 [info] buf_shrink_freelists(): Cleaned freelist for 4096-byte chunks: original length 10, kept 0, dropped 10. Aug 16 09:40:19.000 [info] buf_shrink_freelists(): Cleaned freelist for 8192-byte chunks: original length 2, kept 0, dropped 2. Aug 16 09:40:19.000 [info] buf_shrink_freelists(): Cleaned freelist for 16384-byte chunks: original length 0, kept 0, dropped 0. Aug 16 09:40:19.000 [info] buf_shrink_freelists(): Cleaned freelist for 32768-byte chunks: original length 3, kept 0, dropped 3. Aug 16 09:40:19.000 [info] tor_lockfile_unlock(): Unlocking "C:/Home/Default/.tor/lock"