Tor 0.1.2.19 server crash on Solaris Sparc
Dear Developpers,
I have successfully compiled and run openssl 0.9.8g, libevent 1.3e and tor 0.1.2.19 with gcc-4.2.2 in a Solaris 10 Sparc Zone as a Tor client. As soon as I uncomment ORPort in torrc to enable the server it starts initializing and crashes with a "Bus Error" while checking reachability and bandwidth. When I block port 9001 on the firewall it does not crash, but obviously not work also. :)
Trace of the startup included below, with level info and level debug at the final stage. I do not get a core dumped.
#ulimit -a
core file size (blocks, -c) unlimited data seg size (kbytes, -d) unlimited file size (blocks, -f) unlimited open files (-n) 256 pipe size (512 bytes, -p) 10 stack size (kbytes, -s) 8192 cpu time (seconds, -t) unlimited max user processes (-u) 14117 virtual memory (kbytes, -v) unlimited
Tried to increase open files to 1024 with no difference.
Any help is greatly appreciated. Thanks,
Jan
Feb 09 11:24:46.399 [notice] Tor v0.1.2.19. This is experimental software. Do not rely on it for strong anonymity. Feb 09 11:24:46.404 [warn] You specified a public address '0.0.0.0' for a SOCKS proxy. Other people on the Internet might find your computer and use it as an open SOCKS proxy. Please don't allow this unless you have a good reason. Feb 09 11:24:46.405 [notice] Choosing default nickname 'tor' Feb 09 11:24:46.406 [notice] Your ContactInfo config option is not set. Please consider setting it, so we can contact you if your server is misconfigured or something else goes wrong. Feb 09 11:24:46.410 [notice] Initialized libevent version 1.3e using method event ports. Good. Feb 09 11:24:46.412 [notice] Opening OR listener on 0.0.0.0:9001 Feb 09 11:24:46.413 [notice] Opening Socks listener on 0.0.0.0:9050 Feb 09 11:24:46.413 [notice] Opening Control listener on 0.0.0.0:9051 Feb 09 11:24:46.418 [info] or_state_load(): Loaded state from "/usr/local/tor/var/state" Feb 09 11:24:46.437 [info] crypto_seed_rng(): Seeding RNG from "/dev/urandom" Feb 09 11:24:46.439 [info] configure_nameservers(): Parsing resolver configuration in '/etc/resolv.conf' Feb 09 11:24:46.439 [info] eventdns: Parsing resolv.conf file /etc/resolv.conf Feb 09 11:24:46.441 [info] eventdns: Added nameserver xxxxxxx Feb 09 11:24:46.442 [info] eventdns: Added nameserver xxxxxxx Feb 09 11:24:46.442 [info] eventdns: Setting maximum allowed timeouts to 3 Feb 09 11:24:46.443 [info] eventdns: Setting timeout to 5 Feb 09 11:24:46.444 [info] init_keys(): Reading/making identity key "/usr/local/tor/var/keys/secret_id_key"... Feb 09 11:24:46.620 [info] init_keys(): Reading/making onion key "/usr/local/tor/var/keys/secret_onion_key"... platform Tor 0.1.2.19 on SunOS sun4u published 2008-02-09 10:24:50 opt fingerprint xxxx xxxx xxxx xxxx uptime 0 bandwidth 3145728 6291456 0 onion-key -----BEGIN RSA PUBLIC KEY----- [...] -----END RSA PUBLIC KEY----- signing-key -----BEGIN RSA PUBLIC KEY----- [...] -----END RSA PUBLIC KEY----- opt write-history 2008-02-09 10:24:46 (900 s) opt read-history 2008-02-09 10:24:46 (900 s) [...]
Feb 09 11:24:50.620 [info] init_keys(): Dumping fingerprint to "/usr/local/tor/var/fingerprint"... Feb 09 11:24:50.622 [notice] Your Tor server's identity key fingerprint is 'xxxx xxxx xxxx' Feb 09 11:24:55.294 [info] router_load_routers_from_string(): 1690 elements to add Feb 09 11:24:56.435 [info] router_load_routers_from_string(): 365 elements to add [...] Feb 09 11:24:56.806 [info] router_set_networkstatus(): Setting networkstatus cached from directory server "moria1" at 128.31.0.34:9031 (published 2008-02-08 16:14:02) Feb 09 11:24:56.806 [info] networkstatus_list_update_recent(): Networkstatus from directory server "moria1" at 128.31.0.34:9031 (published 2008-02-08 16:14:02) is now "recent" Feb 09 11:24:57.017 [debug] check_directory_signature(): Signed directory hash starts 4529A66E Feb 09 11:24:57.021 [info] router_set_networkstatus(): Setting networkstatus cached from directory server "tor26" at 86.59.21.38:80 (published 2008-02-08 21:44:01) Feb 09 11:24:57.021 [info] networkstatus_list_update_recent(): Networkstatus from directory server "tor26" at 86.59.21.38:80 (published 2008-02-08 21:44:01) is now "recent" Feb 09 11:24:57.244 [debug] check_directory_signature(): Signed directory hash starts DE69E0AF Feb 09 11:24:57.247 [info] router_set_networkstatus(): Setting networkstatus cached from directory server "dizum" at 194.109.206.212:80 (published 2008-02-08 22:35:27) Feb 09 11:24:57.248 [info] networkstatus_list_update_recent(): Networkstatus from directory server "dizum" at 194.109.206.212:80 (published 2008-02-08 22:35:27) is now "recent" Feb 09 11:24:57.458 [debug] check_directory_signature(): Signed directory hash starts FFF46957 Feb 09 11:24:57.462 [info] router_set_networkstatus(): Setting networkstatus cached from directory server "moria2" at 128.31.0.34:9032 (published 2008-02-08 16:34:41) Feb 09 11:24:57.462 [info] networkstatus_list_update_recent(): Networkstatus from directory server "moria2" at 128.31.0.34:9032 (published 2008-02-08 16:34:41) is now "recent" Feb 09 11:24:57.463 [info] networkstatus_list_update_recent(): Networkstatus from directory server "moria1" at 128.31.0.34:9031 (published 2008-02-08 16:14:02) is no longer "recent" Feb 09 11:24:57.669 [debug] check_directory_signature(): Signed directory hash starts BB7A2DAC Feb 09 11:24:57.672 [info] router_set_networkstatus(): Setting networkstatus cached from directory server "lefkada" at 140.247.60.64:80 (published 2008-02-08 22:09:03) Feb 09 11:24:57.673 [info] networkstatus_list_update_recent(): Networkstatus from directory server "lefkada" at 140.247.60.64:80 (published 2008-02-08 22:09:03) is now "recent" Feb 09 11:24:57.673 [info] networkstatus_list_update_recent(): Networkstatus from directory server "moria2" at 128.31.0.34:9032 (published 2008-02-08 16:34:41) is no longer "recent" Feb 09 11:24:57.674 [info] routerstatus_list_update_from_networkstatus(): Rebuilding router status list. Feb 09 11:24:57.692 [info] routerstatus_list_update_from_networkstatus(): Naming authorities disagree about which key goes with joestorserver. ($86D83F4F853EDFEEAD1EF3B17CE2034F8397A8F6 vs $0731DD94CD90068DAFE31DBC449F1BA36C6DF277) [...] Feb 09 11:24:58.637 [debug] routerstatus_list_update_from_networkstatus(): Router 'FightFascism' is listed by 5/5 directories, named by 2/3, validated by 5/5, and 3/3 recent directories think it's running. Feb 09 11:24:58.638 [warn] Naming authorities disagree about nicknames for $C1D04F2F5E9A0FF9240638BE9805563C03A3D8CB ("PoderosoTorII" vs "PoderosoTorIII") [...] Feb 09 11:24:59.353 [info] circuit_predict_and_launch_new(): Have 0 clean circs (0 internal), need another exit circ. Feb 09 11:24:59.358 [info] choose_good_exit_server_general(): Found 628 servers that might support 0/0 pending connections. Feb 09 11:24:59.363 [info] choose_good_exit_server_general(): Chose exit server 'superbad' [...] Feb 09 11:24:59.670 [info] connection_dir_client_reached_eof(): Received server info (size 3265) from server '87.106.188.238:80' Feb 09 11:24:59.674 [info] router_load_routers_from_string(): 1 elements to add Feb 09 11:24:59.736 [info] connection_dir_client_reached_eof(): Received 1/1 routers requested from 87.106.188.238:80 [...] Feb 09 11:24:59.846 [info] connection_dir_client_reached_eof(): Received networkstatus objects (size 382650) from server '91.121.7.211:80' Feb 09 11:25:00.063 [info] router_set_networkstatus(): Setting networkstatus downloaded from directory server "moria1" at 128.31.0.34:9031 (published 2008-02-09 09:58:14) Feb 09 11:25:00.079 [info] networkstatus_list_update_recent(): Networkstatus from directory server "moria1" at 128.31.0.34:9031 (published 2008-02-09 09:58:14) is now "recent" Feb 09 11:25:00.080 [info] networkstatus_list_update_recent(): Networkstatus from directory server "tor26" at 86.59.21.38:80 (published 2008-02-08 21:44:01) is no longer "recent" Feb 09 11:25:00.081 [info] routerstatus_list_update_from_networkstatus(): Rebuilding router status list. Feb 09 11:25:00.108 [info] routerstatus_list_update_from_networkstatus(): Naming authorities disagree about which key goes with JoesTorServer. ($0731DD94CD90068DAFE31DBC449F1BA36C6DF277 vs $86D83F4F853EDFEEAD1EF3B17CE2034F8397A8F6) [...] Feb 09 11:25:01.589 [info] entry_guards_compute_status(): Summary: Entry 'rfc1149' is reachable, usable and live. Feb 09 11:25:01.589 [info] entry_guards_compute_status(): Summary: Entry 'Bellum' is reachable, unusable and not live. Feb 09 11:25:01.590 [info] entry_guards_compute_status(): Summary: Entry 'SuperDuperLative' is reachable, usable and live. Feb 09 11:25:01.590 [info] entry_guards_compute_status(): Summary: Entry 'lolnode' is reachable, usable and live. Feb 09 11:25:01.590 [debug] tor_version_is_obsolete(): Checking whether version '0.1.2.19' is in '0.1.2.19,0.2.0.11-alpha,0.2.0.12-alpha,0.2.0.15-alpha,0.2.0.18-alpha' Feb 09 11:25:01.590 [debug] tor_version_is_obsolete(): Checking whether version '0.1.2.19' is in '0.1.2.17,0.1.2.18,0.1.2.19,0.2.0.6-alpha,0.2.0.7-alpha,0.2.0.8-alpha,0.2.0.9-alpha,0.2.0.10-alpha,0.2.0.11-alpha,0.2.0.12-alpha,0.2.0.13-alpha,0.2.0.14-alpha,0.2.0.15-alpha,0.2.0.16-alpha,0.2.0.17-alpha,0.2.0.18-alpha' Feb 09 11:25:01.590 [debug] tor_version_is_obsolete(): Checking whether version '0.1.2.19' is in '0.1.2.19,0.2.0.11-alpha,0.2.0.12-alpha,0.2.0.15-alpha,0.2.0.18-alpha' Feb 09 11:25:01.591 [info] routers_update_all_from_networkstatus(): 3/3 statements from version-listing directory authorities say my version is ok. Feb 09 11:25:01.643 [debug] conn_close_if_marked(): Cleaning up connection (fd 14). Feb 09 11:25:01.643 [debug] connection_remove(): removing socket 14 (type Directory), n_conns now 5 Feb 09 11:25:01.644 [debug] _connection_free(): closing fd 14. Feb 09 11:25:01.644 [debug] conn_read_callback(): socket 16 wants to read. Feb 09 11:25:01.891 [debug] connection_tls_continue_handshake(): wanted read Feb 09 11:25:01.892 [debug] global_read_bucket now 6291456. Feb 09 11:25:01.892 [debug] global_write_bucket now 6291456. Feb 09 11:25:01.893 [debug] circuit_remove_handled_ports(): Port 80 is not handled. Feb 09 11:25:01.893 [info] circuit_predict_and_launch_new(): Have 1 clean circs (0 internal), need another exit circ. Feb 09 11:25:01.894 [debug] new_route_len(): Chosen route length 3 (1813 routers available). Feb 09 11:25:01.898 [info] choose_good_exit_server_general(): Found 616 servers that might support 0/0 pending connections. Feb 09 11:25:01.899 [debug] circuit_remove_handled_ports(): Port 80 is not handled. Feb 09 11:25:01.902 [info] choose_good_exit_server_general(): Chose exit server 'almostunknown' Feb 09 11:25:02.319 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'SuperDuperLative' Feb 09 11:25:02.362 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'rfc1149' Feb 09 11:25:02.473 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:02.473 [info] exit circ (length 3, exit almostunknown): rfc1149(open) keinezensurde(closed) almostunknown(closed) Feb 09 11:25:02.474 [debug] command_process_created_cell(): Moving to next skin. Feb 09 11:25:02.474 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:02.509 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:02.510 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:02.510 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:02.511 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:02.511 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:02.512 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:02.513 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:02.513 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:02.596 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:02.597 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:02.597 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:02.597 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:02.598 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:02.599 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:02.599 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:02.600 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:02.600 [debug] connection_edge_process_relay_cell(): Now seen 1 relay cells here. Feb 09 11:25:02.601 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:02.633 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:02.634 [info] exit circ (length 3, exit almostunknown): rfc1149(open) keinezensurde(open) almostunknown(closed) Feb 09 11:25:02.634 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:02.669 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:02.670 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:02.670 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:02.671 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:02.671 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:02.672 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:02.672 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:02.673 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:02.673 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:02.920 [debug] global_read_bucket now 6291456. Feb 09 11:25:02.920 [debug] global_write_bucket now 6291456. Feb 09 11:25:02.971 [info] circuit_predict_and_launch_new(): Have 2 clean circs (0 uptime-internal, 0 internal), need another hidserv circ. Feb 09 11:25:02.972 [debug] new_route_len(): Chosen route length 3 (1813 routers available). Feb 09 11:25:02.974 [debug] onion_extend_cpath(): Path is 0 long; we want 3 Feb 09 11:25:02.975 [debug] onion_extend_cpath(): Chose router rfc1149 for hop 1 (exit is aim1loxal1net) Feb 09 11:25:02.975 [debug] onion_extend_cpath(): Path is 1 long; we want 3 Feb 09 11:25:02.976 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice. Feb 09 11:25:02.979 [debug] onion_extend_cpath(): Chose router petspaper for hop 2 (exit is aim1loxal1net) Feb 09 11:25:02.979 [debug] onion_extend_cpath(): Path is 2 long; we want 3 Feb 09 11:25:02.980 [debug] onion_extend_cpath(): Chose router aim1loxal1net for hop 3 (exit is aim1loxal1net) Feb 09 11:25:02.980 [debug] onion_extend_cpath(): Path is complete: 3 steps long Feb 09 11:25:02.981 [debug] circuit_handle_first_hop(): Looking for firsthop '88.191.14.223:9001' Feb 09 11:25:02.981 [debug] circuit_handle_first_hop(): Conn open. Delivering first onion skin. Feb 09 11:25:02.982 [debug] circuit_send_next_onion_skin(): First skin; sending create cell. Feb 09 11:25:03.018 [debug] circuit_deliver_create_cell(): Chosen circID 23586. Feb 09 11:25:03.019 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:03.019 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'rfc1149' Feb 09 11:25:03.020 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:03.022 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:03.022 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:03.086 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:03.086 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:03.087 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:03.087 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:03.088 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:03.088 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:03.089 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:03.089 [debug] command_process_created_cell(): at OP. Finishing handshake. Feb 09 11:25:03.122 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:03.122 [info] internal (high-uptime) circ (length 3, exit aim1loxal1net): rfc1149(open) petspaper(closed) aim1loxal1net(closed) Feb 09 11:25:03.123 [debug] command_process_created_cell(): Moving to next skin. Feb 09 11:25:03.123 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:03.158 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:03.159 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:03.159 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:03.160 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:03.160 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:03.161 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:03.161 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:03.162 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:03.346 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:03.346 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:03.347 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:03.347 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:03.348 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:03.348 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:03.349 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:03.349 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:03.350 [debug] connection_edge_process_relay_cell(): Now seen 2 relay cells here. Feb 09 11:25:03.350 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:03.383 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:03.384 [info] internal (high-uptime) circ (length 3, exit aim1loxal1net): rfc1149(open) petspaper(open) aim1loxal1net(closed) Feb 09 11:25:03.384 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:03.419 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:03.419 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:03.420 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:03.421 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:03.421 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:03.421 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:03.422 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:03.423 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:03.423 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:04.020 [debug] global_read_bucket now 6291456. Feb 09 11:25:04.021 [debug] global_write_bucket now 6291456. Feb 09 11:25:04.021 [info] circuit_predict_and_launch_new(): Have 3 clean circs (1 uptime-internal, 1 internal), need another hidserv circ. Feb 09 11:25:04.022 [debug] new_route_len(): Chosen route length 3 (1813 routers available). Feb 09 11:25:04.023 [debug] onion_extend_cpath(): Path is 0 long; we want 3 Feb 09 11:25:04.024 [debug] onion_extend_cpath(): Chose router rfc1149 for hop 1 (exit is ArnoldBros1905) Feb 09 11:25:04.025 [debug] onion_extend_cpath(): Path is 1 long; we want 3 Feb 09 11:25:04.025 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice. Feb 09 11:25:04.028 [debug] onion_extend_cpath(): Chose router wiredwings for hop 2 (exit is ArnoldBros1905) Feb 09 11:25:04.029 [debug] onion_extend_cpath(): Path is 2 long; we want 3 Feb 09 11:25:04.029 [debug] onion_extend_cpath(): Chose router ArnoldBros1905 for hop 3 (exit is ArnoldBros1905) Feb 09 11:25:04.030 [debug] onion_extend_cpath(): Path is complete: 3 steps long Feb 09 11:25:04.030 [debug] circuit_handle_first_hop(): Looking for firsthop '88.191.14.223:9001' Feb 09 11:25:04.031 [debug] circuit_handle_first_hop(): Conn open. Delivering first onion skin. Feb 09 11:25:04.031 [debug] circuit_send_next_onion_skin(): First skin; sending create cell. Feb 09 11:25:04.066 [debug] circuit_deliver_create_cell(): Chosen circID 23587. Feb 09 11:25:04.066 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:04.067 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'rfc1149' Feb 09 11:25:04.067 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:04.068 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:04.069 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:04.146 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:04.147 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:04.147 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.147 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.148 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:04.149 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:04.149 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:04.149 [debug] command_process_created_cell(): at OP. Finishing handshake. Feb 09 11:25:04.183 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:04.184 [info] internal (high-uptime) circ (length 3, exit ArnoldBros1905): rfc1149(open) wiredwings(closed) ArnoldBros1905(closed) Feb 09 11:25:04.184 [debug] command_process_created_cell(): Moving to next skin. Feb 09 11:25:04.184 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:04.219 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:04.220 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:04.220 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:04.224 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:04.225 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:04.225 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:04.226 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:04.227 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:04.301 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:04.302 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:04.302 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.302 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.303 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:04.304 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:04.304 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:04.304 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:04.305 [debug] connection_edge_process_relay_cell(): Now seen 3 relay cells here. Feb 09 11:25:04.305 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:04.340 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:04.341 [info] internal (high-uptime) circ (length 3, exit ArnoldBros1905): rfc1149(open) wiredwings(open) ArnoldBros1905(closed) Feb 09 11:25:04.341 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:04.376 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:04.377 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:04.377 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:04.378 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:04.378 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:04.380 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:04.381 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:04.382 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:04.382 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:04.544 [debug] conn_read_callback(): socket 16 wants to read. Feb 09 11:25:04.545 [debug] connection_read_to_buf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:04.545 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.546 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.546 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:04.547 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:04.547 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:04.548 [debug] command_process_created_cell(): at OP. Finishing handshake. Feb 09 11:25:04.580 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:04.581 [info] exit circ (length 3, exit superbad): SuperDuperLative(open) DrazziBTorNode(closed) superbad(closed) Feb 09 11:25:04.582 [debug] command_process_created_cell(): Moving to next skin. Feb 09 11:25:04.582 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:04.617 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:04.617 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:04.618 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:04.618 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:04.619 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:04.619 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:04.620 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:04.620 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.621 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.621 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:04.622 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:04.622 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:04.623 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:04.623 [debug] connection_edge_process_relay_cell(): Now seen 4 relay cells here. Feb 09 11:25:04.624 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:04.656 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:04.657 [info] internal (high-uptime) circ (length 3, exit ArnoldBros1905): rfc1149(open) wiredwings(open) ArnoldBros1905(open) Feb 09 11:25:04.657 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:04.657 [info] circuit_send_next_onion_skin(): circuit built! Feb 09 11:25:04.658 [notice] Tor has successfully opened a circuit. Looks like client functionality is working. Feb 09 11:25:04.659 [notice] Now checking whether ORPort x.x.x.x:9001 is reachable... (this may take up to 20 minutes -- look for log messages indicating success) Feb 09 11:25:04.661 [info] consider_testing_reachability(): Testing reachability of my ORPort: x.x.x.x:9001. Feb 09 11:25:04.661 [debug] new_route_len(): Chosen route length 3 (1813 routers available). Feb 09 11:25:04.662 [info] onion_pick_cpath_exit(): Using requested exit node 'tor' Feb 09 11:25:04.663 [debug] onion_extend_cpath(): Path is 0 long; we want 3 Feb 09 11:25:04.664 [debug] onion_extend_cpath(): Chose router rfc1149 for hop 1 (exit is tor) Feb 09 11:25:04.664 [debug] onion_extend_cpath(): Path is 1 long; we want 3 Feb 09 11:25:04.664 [debug] choose_good_middle_server(): Contemplating intermediate hop: random choice. Feb 09 11:25:04.683 [info] compute_preferred_testing_list(): Looking for middle server that doesn't have the reachability bug, and chose 'Gollum'. Great. Feb 09 11:25:04.684 [debug] onion_extend_cpath(): Chose router Gollum for hop 2 (exit is tor) Feb 09 11:25:04.685 [debug] onion_extend_cpath(): Path is 2 long; we want 3 Feb 09 11:25:04.685 [debug] onion_extend_cpath(): Chose router tor for hop 3 (exit is tor) Feb 09 11:25:04.685 [debug] onion_extend_cpath(): Path is complete: 3 steps long Feb 09 11:25:04.686 [debug] circuit_handle_first_hop(): Looking for firsthop '88.191.14.223:9001' Feb 09 11:25:04.686 [debug] circuit_handle_first_hop(): Conn open. Delivering first onion skin. Feb 09 11:25:04.687 [debug] circuit_send_next_onion_skin(): First skin; sending create cell. Feb 09 11:25:04.722 [debug] circuit_deliver_create_cell(): Chosen circID 23588. Feb 09 11:25:04.722 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:04.723 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'rfc1149' Feb 09 11:25:04.723 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:04.724 [debug] conn_write_callback(): socket 16 wants to write. Feb 09 11:25:04.725 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:04.725 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:04.726 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:04.726 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:04.727 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:04.795 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:04.796 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:04.796 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.797 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:04.797 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:04.798 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:04.798 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:04.799 [debug] command_process_created_cell(): at OP. Finishing handshake. Feb 09 11:25:04.831 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:04.832 [info] internal circ (length 3, exit tor): rfc1149(open) $BF39AFADE1ECAB0373459236D31C6A0E3B59CB82(closed) $795EC4D74109C3B4CD7ECB2B652AEF51F99CA5FB(closed) Feb 09 11:25:04.833 [debug] command_process_created_cell(): Moving to next skin. Feb 09 11:25:04.833 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:04.868 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:04.868 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:04.869 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:04.869 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:04.870 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:04.870 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:04.871 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:04.872 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:05.070 [debug] global_read_bucket now 6291456. Feb 09 11:25:05.071 [debug] global_write_bucket now 6291456. Feb 09 11:25:05.738 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:05.738 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:05.739 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:05.739 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:05.740 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:05.740 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:05.741 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:05.741 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:05.742 [debug] connection_edge_process_relay_cell(): Now seen 5 relay cells here. Feb 09 11:25:05.742 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:05.775 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:05.775 [info] exit circ (length 3, exit almostunknown): rfc1149(open) keinezensurde(open) almostunknown(open) Feb 09 11:25:05.776 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:05.776 [info] circuit_send_next_onion_skin(): circuit built! Feb 09 11:25:05.776 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:06.080 [debug] global_read_bucket now 6291456. Feb 09 11:25:06.452 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:06.452 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:06.452 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:06.452 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:06.453 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:06.453 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:06.453 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:06.453 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:06.453 [debug] connection_edge_process_relay_cell(): Now seen 6 relay cells here. Feb 09 11:25:06.453 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:06.486 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:06.487 [info] internal (high-uptime) circ (length 3, exit aim1loxal1net): rfc1149(open) petspaper(open) aim1loxal1net(open) Feb 09 11:25:06.487 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:06.488 [info] circuit_send_next_onion_skin(): circuit built! Feb 09 11:25:06.488 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:06.553 [debug] conn_read_callback(): socket 16 wants to read. Feb 09 11:25:06.554 [debug] connection_read_to_buf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:06.554 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:06.554 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:06.555 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:06.556 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:06.556 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:06.557 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:06.557 [debug] connection_edge_process_relay_cell(): Now seen 7 relay cells here. Feb 09 11:25:06.557 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:06.590 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:06.590 [info] exit circ (length 3, exit superbad): SuperDuperLative(open) DrazziBTorNode(open) superbad(closed) Feb 09 11:25:06.591 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:06.628 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:06.629 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:06.629 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:06.630 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:06.630 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:06.631 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:06.631 [debug] conn_write_callback(): socket 16 wants to write. Feb 09 11:25:06.632 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:06.632 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:06.685 [debug] conn_read_callback(): socket 11 wants to read. Feb 09 11:25:06.686 [debug] connection_read_to_buf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:06.686 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:06.687 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:06.688 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:06.688 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:06.688 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:06.689 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:06.689 [debug] connection_edge_process_relay_cell(): Now seen 8 relay cells here. Feb 09 11:25:06.690 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:06.723 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:06.723 [info] internal circ (length 3, exit tor): rfc1149(open) $BF39AFADE1ECAB0373459236D31C6A0E3B59CB82(open) $795EC4D74109C3B4CD7ECB2B652AEF51F99CA5FB(closed) Feb 09 11:25:06.724 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:06.759 [debug] circuit_send_next_onion_skin(): Sending extend relay cell. Feb 09 11:25:06.759 [debug] relay_send_command_from_edge(): delivering 6 cell forward. Feb 09 11:25:06.760 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:06.760 [debug] circuit_package_relay_cell(): crypting a layer of the relay cell. Feb 09 11:25:06.761 [debug] write_to_buf(): added 512 bytes to buf (now 512 total). Feb 09 11:25:06.761 [debug] connection_or_process_cells_from_inbuf(): 11: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:06.762 [debug] conn_write_callback(): socket 11 wants to write. Feb 09 11:25:06.763 [debug] flush_buf_tls_impl(): flushed 512 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:06.763 [debug] connection_handle_write(): After TLS write of 512: 0 read, 586 written Feb 09 11:25:07.091 [debug] global_read_bucket now 6291456. Feb 09 11:25:07.092 [debug] global_write_bucket now 6291456. Feb 09 11:25:07.719 [debug] conn_read_callback(): socket 5 wants to read. Feb 09 11:25:07.720 [debug] connection_handle_listener_read(): Connection accepted on socket 14 (child of fd 5). Feb 09 11:25:07.721 [debug] connection_add(): new conn type OR, socket 14, n_conns 7. Feb 09 11:25:07.721 [debug] connection_tls_start_handshake(): starting TLS handshake on fd 14 Feb 09 11:25:07.722 [debug] connection_tls_continue_handshake(): wanted read Feb 09 11:25:07.732 [debug] conn_read_callback(): socket 14 wants to read. Feb 09 11:25:07.798 [debug] connection_tls_continue_handshake(): wanted read Feb 09 11:25:08.033 [debug] conn_read_callback(): socket 14 wants to read. Feb 09 11:25:08.076 [debug] connection_tls_finish_handshake(): tls handshake done. verifying. Feb 09 11:25:08.078 [debug] connection_or_check_valid_handshake(): The certificate seems to be valid on incoming connection with [scrubbed]:6169 Feb 09 11:25:08.079 [debug] circuit_n_conn_done(): or_conn to Gollum, status=1 Feb 09 11:25:08.080 [debug] connection_or_process_cells_from_inbuf(): 14: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:08.541 [debug] conn_read_callback(): socket 14 wants to read. Feb 09 11:25:08.542 [debug] connection_read_to_buf(): 14: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:08.543 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:08.543 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:08.544 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:08.544 [debug] connection_read_to_buf(): After TLS read of 512: 1908 read, 1450 written Feb 09 11:25:08.544 [debug] connection_or_process_cells_from_inbuf(): 14: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:08.545 [debug] write_to_buf(): added 1 bytes to buf (now 1 total). Feb 09 11:25:08.545 [debug] write_to_buf(): added 8 bytes to buf (now 9 total). Feb 09 11:25:08.546 [debug] write_to_buf(): added 186 bytes to buf (now 195 total). Feb 09 11:25:08.546 [debug] command_process_create_cell(): success: handed off onionskin. Feb 09 11:25:08.546 [debug] connection_or_process_cells_from_inbuf(): 14: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:08.547 [debug] conn_write_callback(): socket 15 wants to write. Feb 09 11:25:08.570 [debug] flush_buf(): 15: flushed 195 bytes, 0 ready to flush, 0 remain. Feb 09 11:25:08.571 [debug] conn_read_callback(): socket 16 wants to read. Feb 09 11:25:08.572 [debug] connection_read_to_buf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). at_most 4096. Feb 09 11:25:08.572 [debug] read_to_buf_tls(): start: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:08.572 [debug] read_to_buf_tls_impl(): before: 0 on buf, 0 pending, at_most 4096. Feb 09 11:25:08.573 [debug] read_to_buf_tls_impl(): Read 512 bytes. 512 on inbuf; 0 pending Feb 09 11:25:08.573 [debug] connection_read_to_buf(): After TLS read of 512: 586 read, 0 written Feb 09 11:25:08.574 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 512 (0 pending in tls object). Feb 09 11:25:08.574 [debug] circuit_receive_relay_cell(): Sending to origin. Feb 09 11:25:08.575 [debug] connection_edge_process_relay_cell(): Now seen 9 relay cells here. Feb 09 11:25:08.575 [debug] connection_edge_process_relay_cell(): Got an extended cell! Yay. Feb 09 11:25:08.648 [info] circuit_finish_handshake(): Finished building circuit hop: Feb 09 11:25:08.648 [info] exit circ (length 3, exit superbad): SuperDuperLative(open) DrazziBTorNode(open) superbad(open) Feb 09 11:25:08.649 [debug] circuit_send_next_onion_skin(): starting to send subsequent skin. Feb 09 11:25:08.649 [info] circuit_send_next_onion_skin(): circuit built! Feb 09 11:25:08.650 [debug] connection_or_process_cells_from_inbuf(): 16: starting, inbuf_datalen 0 (0 pending in tls object). Feb 09 11:25:08.692 [debug] cpuworker_main(): onion_skin_server_handshake succeeded. Feb 09 11:25:08.693 [debug] cpuworker_main(): finished writing response. Feb 09 11:25:08.694 [debug] conn_read_callback(): socket 15 wants to read. Feb 09 11:25:08.694 [debug] read_to_buf_impl(): Read 229 bytes. 229 on inbuf. Bus Error
Feb 09 11:25:08.712 [info] cpuworker_main(): CPU worker exiting because Tor process closed connection (either rotated keys or died).
[Automatically added by flyspray2trac: Operating System: Solaris]
Trac:
Username: jaba