an abort() in delete_log
One of my short lived Tors (start with fresh data directory, run for a minute, sent TERM):
After sending a SIGNAL TERM to my tor, it died with an abort() in delete_log():
(gdb) bt #0 0x556f583b in raise () from /lib/tls/libc.so.6 #1 0x556f6fa2 in abort () from /lib/tls/libc.so.6 #2 (closed) 0x080ac462 in delete_log (victim=0x80fd2c0) at log.c:339 #3 (closed) 0x080ac2af in logv (severity=6, domain=65536, funcname=0x80d2301 "dnsworker_main", format=0x80d22a0 "DNS worker exiting because Tor process closed connection (either pruned idle dnsworker or died).", ap=0x56825960 "") at log.c:227 #4 (closed) 0x080ac332 in _log_fn (severity=6, domain=65536, fn=0x80d2301 "dnsworker_main", format=0x80d22a0 "DNS worker exiting because Tor process closed connection (either pruned idle dnsworker or died).") at log.c:251 #5 (closed) 0x080878ad in dnsworker_main (data=0x0) at dns.c:815 #6 (closed) 0x080b181e in tor_pthread_helper_fn (_data=0x0) at compat.c:819 #7 (closed) 0x556b7b63 in start_thread () from /lib/tls/libpthread.so.0 #8 (closed) 0x557a518a in clone () from /lib/tls/libc.so.6
[Automatically added by flyspray2trac: Operating System: All]
Activity
changed milestone to %post 0.1.2.x
info level log: Dec 19 12:33:02.352 [info] connection_ap_make_bridge(): Making AP bridge to 127.0.0.1:19031 ... Dec 19 12:33:02.353 [info] exit circ (length 3): tor13(open) tor23(open) tor5(open) Dec 19 12:33:02.353 [info] connection_ap_handshake_send_begin(): Address/port sent, ap socket 35, n_circ_id 16879 Dec 19 12:33:02.353 [info] connection_ap_make_bridge(): ... AP bridge created and connected. Dec 19 12:33:02.353 [info] connection_ap_make_bridge(): Making AP bridge to 127.0.0.2:19032 ... Dec 19 12:33:02.353 [info] exit circ (length 3): tor13(open) tor23(open) tor5(open) Dec 19 12:33:02.353 [info] connection_ap_handshake_send_begin(): Address/port sent, ap socket 37, n_circ_id 16879 Dec 19 12:33:02.353 [info] connection_ap_make_bridge(): ... AP bridge created and connected. Dec 19 12:33:02.353 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:02.353 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:02.353 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:02.353 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:02.355 [info] connection_edge_process_relay_cell_not_open(): 'connected' received after 0 seconds. Dec 19 12:33:02.355 [info] exit circ (length 3): tor13(open) tor23(open) tor5(open) Dec 19 12:33:02.355 [info] connection_edge_process_relay_cell_not_open(): 'connected' received after 0 seconds. Dec 19 12:33:02.355 [info] exit circ (length 3): tor13(open) tor23(open) tor5(open) Dec 19 12:33:02.357 [info] connection_edge_process_relay_cell(): 37: end cell (closed normally) for stream 50334. Removing stream. Dec 19 12:33:02.357 [info] connection_edge_process_relay_cell(): 35: end cell (closed normally) for stream 50333. Removing stream. Dec 19 12:33:02.357 [info] connection_dir_client_reached_eof(): Uploading rendezvous descriptor: finished with status 200 ("Service descriptor stored") Dec 19 12:33:02.357 [info] connection_dir_client_reached_eof(): Uploading rendezvous descriptor: finished with status 200 ("Service descriptor stored") Dec 19 12:33:12.207 [info] rend_mid_establish_intro(): Received an ESTABLISH_INTRO request on circuit 23324 Dec 19 12:33:12.207 [info] rend_mid_establish_intro(): Established introduction point on circuit 23324 for service ixio3yn227swus2q Dec 19 12:33:18.426 [info] update_router_descriptor_downloads(): There are not many downloadable routerdescs, but we've been waiting long enough (60 seconds). Downloading. Dec 19 12:33:18.426 [info] update_router_descriptor_downloads(): Launching 1 request for 1 router, 128 at a time Dec 19 12:33:18.427 [info] connection_dir_client_reached_eof(): Received server info (size 1102) from server '127.0.0.1:19031' Dec 19 12:33:18.438 [info] connection_dir_client_reached_eof(): Received 1/1 routers requested from 127.0.0.1:19031 Dec 19 12:33:26.190 [info] rend_mid_establish_intro(): Received an ESTABLISH_INTRO request on circuit 5875 Dec 19 12:33:26.190 [info] rend_mid_establish_intro(): Established introduction point on circuit 5875 for service i4t5zhvejqu475oy Dec 19 12:33:28.244 [info] circuit_extend(): Next router (127.0.0.30:19030) not connected. Connecting. Dec 19 12:33:30.149 [info] connection_control_process_inbuf_v0(): Detected v1 control protocol on connection (fd 37) Dec 19 12:33:30.149 [info] handle_control_authenticate(): Authenticated control connection (37) Dec 19 12:33:30.149 [err] signal_callback(): Catching signal TERM, exiting cleanly. Dec 19 12:33:30.206 [info] cpuworker_main(): CPU worker exiting because Tor process closed connection (either rotated keys or died). Dec 19 12:33:34.263 [notice] Tor 0.1.1.10-alpha-cvs opening log file. Dec 19 12:33:34.263 [info] or_state_load(): Initialized state Dec 19 12:33:34.263 [info] or_state_save(): Saved state to "data/state" Dec 19 12:33:34.263 [info] rend_service_load_keys(): Loading hidden-service keys from "hid1" Dec 19 12:33:34.263 [info] check_private_dir(): Creating directory hid1 Dec 19 12:33:34.263 [info] init_key_from_file(): No key found in "hid1/private_key"; generating fresh key. Dec 19 12:33:34.331 [info] init_key_from_file(): Generated key seems valid Dec 19 12:33:34.331 [info] rend_service_load_keys(): Loading hidden-service keys from "hid2" Dec 19 12:33:34.346 [info] crypto_global_init(): Initializing OpenSSL engine support. Dec 19 12:33:34.348 [info] Using default implementation for RSA Dec 19 12:33:34.348 [info] Using default implementation for DH Dec 19 12:33:34.348 [info] Using default implementation for RAND Dec 19 12:33:34.348 [info] Using default implementation for SHA1 Dec 19 12:33:34.348 [info] Using default implementation for 3DES Dec 19 12:33:34.348 [info] Using default implementation for AES Dec 19 12:33:34.348 [info] crypto_seed_rng(): Seeding RNG from "/dev/urandom" Dec 19 12:33:34.348 [info] check_private_dir(): Creating directory data/keys Dec 19 12:33:34.348 [info] init_keys(): Reading/making identity key "data/keys/secret_id_key"... Dec 19 12:33:34.348 [info] init_key_from_file(): No key found in "data/keys/secret_id_key"; generating fresh key. Dec 19 12:33:34.581 [info] init_key_from_file(): Generated key seems valid Dec 19 12:33:34.581 [info] init_keys(): Reading/making onion key "data/keys/secret_onion_key"... Dec 19 12:33:34.581 [info] init_key_from_file(): No key found in "data/keys/secret_onion_key"; generating fresh key. Dec 19 12:33:34.719 [info] init_key_from_file(): Generated key seems valid Dec 19 12:33:34.824 [info] config_expand_exit_policy_aliases(): Expanded 'reject private:*,reject *:25,reject *:119,reject *:135-139,reject *:445,reject *:465,reject :587,reject :1214,reject :4661-4666,reject :6346-6429,reject :6699,reject :6881-6999,accept :' to 'reject 0.0.0.0/8:,reject 169.254.0.0/16:,reject 127.0.0.0/8:,reject 192.168.0.0/16:,reject 10.0.0.0/8:,reject 172.16.0.0/12:,reject *:25,reject *:119,reject *:135-139,reject *:445,reject *:465,reject *:587,reject *:1214,reject *:4661-4666,reject *:6346-6429,reject *:6699,reject *:6881-6999,accept :' Dec 19 12:33:34.827 [info] init_keys(): Dumping descriptor to "data/router.desc"... Dec 19 12:33:34.828 [info] init_keys(): Dumping fingerprint to "data/fingerprint"... Dec 19 12:33:34.828 [info] read_file_to_str(): Could not stat "data/cached-routers". Dec 19 12:33:34.828 [info] read_file_to_str(): Could not stat "data/cached-routers.new". Dec 19 12:33:34.828 [notice] I learned some more directory information, but not enough to build a circuit. Dec 19 12:33:34.828 [notice] update_router_descriptor_downloads(): Launching request for all routers Dec 19 12:33:36.299 [info] connection_read_to_buf(): tls error. breaking (nickname $8A00895D073EE39578BF1701EE156AC8D1BC8981, address 127.0.0.43). Dec 19 12:33:36.599 [info] connection_dir_client_reached_eof(): eof (status 200) after uploading server descriptor: finished. Dec 19 12:33:36.611 [info] connection_dir_client_reached_eof(): Received running-routers list (size 315451) Dec 19 12:33:36.713 [info] connection_dir_client_reached_eof(): Received networkstatus objects (size 1775078) from server '127.0.0.1:19031' Dec 19 12:33:36.783 [info] router_set_networkstatus(): Setting networkstatus downloaded from directory server at 127.0.0.1:19031 (published 2005-12-19 11:32:57) Dec 19 12:33:36.785 [info] networkstatus_list_update_recent(): Networkstatus from directory server at 127.0.0.1:19031 (published 2005-12-19 11:32:57) is now "recent" Dec 19 12:33:36.947 [info] router_set_networkstatus(): Setting networkstatus downloaded from directory server at 127.0.0.2:19032 (published 2005-12-19 11:31:33) Dec 19 12:33:36.949 [info] networkstatus_list_update_recent(): Networkstatus from directory server at 127.0.0.2:19032 (published 2005-12-19 11:31:33) is now "recent" Dec 19 12:33:37.046 [info] routerstatus_list_update_from_networkstatus(): Rebuilding router status list. Dec 19 12:33:37.050 [info] routers_update_all_from_networkstatus(): 0/2 recent directories think my version is ok. Dec 19 12:33:37.051 [notice] I learned some more directory information, but not enough to build a circuit. Dec 19 12:33:37.051 [info] connection_dir_client_reached_eof(): eof (status 200) after uploading server descriptor: finished. Dec 19 12:33:37.203 [info] connection_dir_client_reached_eof(): Received server info (size 7089072) from server '127.0.0.2:19032' Dec 19 12:33:49.166 [notice] We now have enough directory information to build circuits. Dec 19 12:33:49.222 [info] rend_services_introduce(): Picked router tor18 as an intro point for upxlw4s7cpagkusq. Dec 19 12:33:49.222 [info] rend_services_introduce(): Picked router tor15 as an intro point for upxlw4s7cpagkusq. Dec 19 12:33:49.222 [info] rend_services_introduce(): Picked router tor25 as an intro point for upxlw4s7cpagkusq. Dec 19 12:33:49.222 [info] rend_service_launch_establish_intro(): Launching circuit to introduction point $5CFB4ED85FA9AC54E342172D9FD8DB571FBDF02A for service upxlw4s7cpagkusq Dec 19 12:33:49.222 [info] onion_pick_cpath_exit(): Using requested exit node 'tor18' Dec 19 12:33:49.224 [info] rend_service_launch_establish_intro(): Launching circuit to introduction point $ADCA0334105CEBA222E1D78B348F1ADCA9C065E6 for service upxlw4s7cpagkusq Dec 19 12:33:49.224 [info] onion_pick_cpath_exit(): Using requested exit node 'tor15' Dec 19 12:33:49.226 [info] rend_service_launch_establish_intro(): Launching circuit to introduction point $44A750378A4D0238843CF07B2137FAEE367A23FA for service upxlw4s7cpagkusq Dec 19 12:33:49.226 [info] onion_pick_cpath_exit(): Using requested exit node 'tor25' Dec 19 12:33:49.228 [info] rend_services_introduce(): Picked router tor5 as an intro point for pncas3abo2uirlci. Dec 19 12:33:49.228 [info] rend_services_introduce(): Picked router tor12 as an intro point for pncas3abo2uirlci. Dec 19 12:33:49.228 [info] rend_services_introduce(): Picked router tor28 as an intro point for pncas3abo2uirlci. Dec 19 12:33:49.228 [info] rend_service_launch_establish_intro(): Launching circuit to introduction point $D3F05C619BAD600DDCD11FCE0C202B3B4E01431D for service pncas3abo2uirlci Dec 19 12:33:49.228 [info] onion_pick_cpath_exit(): Using requested exit node 'tor5' Dec 19 12:33:49.230 [info] rend_service_launch_establish_intro(): Launching circuit to introduction point $8A00895D073EE39578BF1701EE156AC8D1BC8981 for service pncas3abo2uirlci Dec 19 12:33:49.230 [info] onion_pick_cpath_exit(): Using requested exit node 'tor12' Dec 19 12:33:49.231 [info] rend_service_launch_establish_intro(): Launching circuit to introduction point $3B832D2A9C89078628161782D87E83DC96F7E14F for service pncas3abo2uirlci Dec 19 12:33:49.231 [info] onion_pick_cpath_exit(): Using requested exit node 'tor28' Dec 19 12:33:49.233 [info] circuit_predict_and_launch_new(): Have 0 clean circs (0 internal), need another exit circ. Dec 19 12:33:49.234 [info] choose_good_exit_server_general(): Found 36 servers that might support 0/0 pending connections. Dec 19 12:33:49.234 [info] choose_good_exit_server_general(): Chose exit server 'tor1' Dec 19 12:33:49.263 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor17' Dec 19 12:33:49.265 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor17' Dec 19 12:33:49.278 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.278 [info] internal (high-uptime) circ (length 3, exit tor18): tor17(open) tor42(closed) tor18(closed) Dec 19 12:33:49.356 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor4' Dec 19 12:33:49.360 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor22' Dec 19 12:33:49.363 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor7' Dec 19 12:33:49.366 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor21' Dec 19 12:33:49.368 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.368 [info] internal (high-uptime) circ (length 3, exit tor12): tor17(open) tor1(closed) tor12(closed) Dec 19 12:33:49.379 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor8' Dec 19 12:33:49.388 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.388 [info] internal (high-uptime) circ (length 3, exit tor18): tor17(open) tor42(open) tor18(closed) Dec 19 12:33:49.392 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.392 [info] internal (high-uptime) circ (length 3, exit tor28): tor4(open) tor19(closed) tor28(closed) Dec 19 12:33:49.396 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.396 [info] internal (high-uptime) circ (length 3, exit tor25): tor7(open) tor18(closed) tor25(closed) Dec 19 12:33:49.400 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.400 [info] internal (high-uptime) circ (length 3, exit tor12): tor17(open) tor1(open) tor12(closed) Dec 19 12:33:49.410 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.410 [info] exit circ (length 3, exit tor1): tor8(open) tor15(closed) tor1(closed) Dec 19 12:33:49.418 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.418 [info] internal (high-uptime) circ (length 3, exit tor15): tor21(open) tor3(closed) tor15(closed) Dec 19 12:33:49.422 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.422 [info] internal (high-uptime) circ (length 3, exit tor5): tor22(open) tor9(closed) tor5(closed) Dec 19 12:33:49.433 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.433 [info] internal (high-uptime) circ (length 3, exit tor18): tor17(open) tor42(open) tor18(open) Dec 19 12:33:49.433 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:49.433 [notice] Tor has successfully opened a circuit. Looks like it's working. Dec 19 12:33:49.433 [info] rend_service_intro_has_opened(): Established circuit 9785 as introduction point for service upxlw4s7cpagkusq Dec 19 12:33:49.438 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.438 [info] internal (high-uptime) circ (length 3, exit tor25): tor7(open) tor18(open) tor25(closed) Dec 19 12:33:49.443 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:49.443 [info] internal (high-uptime) circ (length 3, exit tor12): tor17(open) tor1(open) tor12(open) Dec 19 12:33:49.443 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:49.443 [info] rend_service_intro_has_opened(): Established circuit 9786 as introduction point for service pncas3abo2uirlci Dec 19 12:33:49.534 [info] connection_dir_client_reached_eof(): Received directory (size 7404565) from server '127.0.0.2:19032' Dec 19 12:33:50.250 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.250 [info] exit circ (length 3, exit tor1): tor8(open) tor15(open) tor1(closed) Dec 19 12:33:50.254 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.254 [info] internal (high-uptime) circ (length 3, exit tor15): tor21(open) tor3(open) tor15(closed) Dec 19 12:33:50.259 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.259 [info] internal (high-uptime) circ (length 3, exit tor5): tor22(open) tor9(open) tor5(closed) Dec 19 12:33:50.263 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.263 [info] internal (high-uptime) circ (length 3, exit tor28): tor4(open) tor19(open) tor28(closed) Dec 19 12:33:50.265 [info] circuit_predict_and_launch_new(): Have 1 clean circs (0 internal), need another exit circ. Dec 19 12:33:50.267 [info] choose_good_exit_server_general(): Found 36 servers that might support 0/0 pending connections. Dec 19 12:33:50.267 [info] choose_good_exit_server_general(): Chose exit server 'tor15' Dec 19 12:33:50.271 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor21' Dec 19 12:33:50.273 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.273 [info] internal (high-uptime) circ (length 3, exit tor25): tor7(open) tor18(open) tor25(open) Dec 19 12:33:50.273 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:50.273 [info] rend_service_intro_has_opened(): Established circuit 8716 as introduction point for service upxlw4s7cpagkusq Dec 19 12:33:50.285 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.285 [info] internal (high-uptime) circ (length 3, exit tor28): tor4(open) tor19(open) tor28(open) Dec 19 12:33:50.285 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:50.285 [info] rend_service_intro_has_opened(): Established circuit 24475 as introduction point for service pncas3abo2uirlci Dec 19 12:33:50.296 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.297 [info] exit circ (length 3, exit tor15): tor21(open) tor19(closed) tor15(closed) Dec 19 12:33:50.310 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.310 [info] internal (high-uptime) circ (length 3, exit tor5): tor22(open) tor9(open) tor5(open) Dec 19 12:33:50.310 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:50.310 [info] rend_service_intro_has_opened(): Established circuit 17670 as introduction point for service pncas3abo2uirlci Dec 19 12:33:50.315 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.315 [info] exit circ (length 3, exit tor15): tor21(open) tor19(open) tor15(closed) Dec 19 12:33:50.326 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.326 [info] exit circ (length 3, exit tor15): tor21(open) tor19(open) tor15(open) Dec 19 12:33:50.326 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:50.328 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.328 [info] internal (high-uptime) circ (length 3, exit tor15): tor21(open) tor3(open) tor15(open) Dec 19 12:33:50.328 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:50.328 [info] rend_service_intro_has_opened(): Established circuit 51740 as introduction point for service upxlw4s7cpagkusq Dec 19 12:33:50.333 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:50.333 [info] exit circ (length 3, exit tor1): tor8(open) tor15(open) tor1(open) Dec 19 12:33:50.333 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:51.276 [info] circuit_predict_and_launch_new(): Have 2 clean circs (0 internal), need another internal circ for my hidden service. Dec 19 12:33:51.308 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor30' Dec 19 12:33:51.317 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:51.317 [info] internal (high-uptime) circ (length 3, exit tor22): tor30(open) tor8(closed) tor22(closed) Dec 19 12:33:51.328 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:51.328 [info] internal (high-uptime) circ (length 3, exit tor22): tor30(open) tor8(open) tor22(closed) Dec 19 12:33:51.339 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:51.339 [info] internal (high-uptime) circ (length 3, exit tor22): tor30(open) tor8(open) tor22(open) Dec 19 12:33:51.339 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:52.280 [info] circuit_predict_and_launch_new(): Have 3 clean circs (1 internal), need another internal circ for my hidden service. Dec 19 12:33:52.308 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor32' Dec 19 12:33:52.317 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:52.317 [info] internal (high-uptime) circ (length 3, exit tor20): tor32(open) tor16(closed) tor20(closed) Dec 19 12:33:52.327 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:52.327 [info] internal (high-uptime) circ (length 3, exit tor20): tor32(open) tor16(open) tor20(closed) Dec 19 12:33:52.338 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:52.338 [info] internal (high-uptime) circ (length 3, exit tor20): tor32(open) tor16(open) tor20(open) Dec 19 12:33:52.338 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:53.283 [info] circuit_predict_and_launch_new(): Have 4 clean circs (2 internal), need another internal circ for my hidden service. Dec 19 12:33:53.311 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor6' Dec 19 12:33:53.319 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:53.319 [info] internal (high-uptime) circ (length 3, exit tor9): tor6(open) tor45(closed) tor9(closed) Dec 19 12:33:53.330 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:53.330 [info] internal (high-uptime) circ (length 3, exit tor9): tor6(open) tor45(open) tor9(closed) Dec 19 12:33:53.341 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:33:53.341 [info] internal (high-uptime) circ (length 3, exit tor9): tor6(open) tor45(open) tor9(open) Dec 19 12:33:53.341 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:33:56.302 [info] connection_ap_make_bridge(): Making AP bridge to 127.0.0.1:19031 ... Dec 19 12:33:56.302 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.302 [info] connection_ap_handshake_send_begin(): Address/port sent, ap socket 30, n_circ_id 51741 Dec 19 12:33:56.302 [info] connection_ap_make_bridge(): ... AP bridge created and connected. Dec 19 12:33:56.302 [info] connection_ap_make_bridge(): Making AP bridge to 127.0.0.2:19032 ... Dec 19 12:33:56.302 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.302 [info] connection_ap_handshake_send_begin(): Address/port sent, ap socket 32, n_circ_id 51741 Dec 19 12:33:56.302 [info] connection_ap_make_bridge(): ... AP bridge created and connected. Dec 19 12:33:56.305 [info] connection_ap_make_bridge(): Making AP bridge to 127.0.0.1:19031 ... Dec 19 12:33:56.305 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.305 [info] connection_ap_handshake_send_begin(): Address/port sent, ap socket 34, n_circ_id 51741 Dec 19 12:33:56.305 [info] connection_ap_make_bridge(): ... AP bridge created and connected. Dec 19 12:33:56.305 [info] connection_ap_make_bridge(): Making AP bridge to 127.0.0.2:19032 ... Dec 19 12:33:56.305 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.305 [info] connection_ap_handshake_send_begin(): Address/port sent, ap socket 36, n_circ_id 51741 Dec 19 12:33:56.305 [info] connection_ap_make_bridge(): ... AP bridge created and connected. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.305 [info] connection_edge_process_inbuf(): data from edge while in 'waiting for connect' state. Leaving it on buffer. Dec 19 12:33:56.307 [info] connection_edge_process_relay_cell_not_open(): 'connected' received after 0 seconds. Dec 19 12:33:56.307 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.308 [info] connection_edge_process_relay_cell_not_open(): 'connected' received after 0 seconds. Dec 19 12:33:56.308 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.308 [info] connection_edge_process_relay_cell_not_open(): 'connected' received after 0 seconds. Dec 19 12:33:56.308 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.308 [info] connection_edge_process_relay_cell_not_open(): 'connected' received after 0 seconds. Dec 19 12:33:56.308 [info] exit circ (length 3): tor21(open) tor19(open) tor15(open) Dec 19 12:33:56.352 [info] connection_edge_process_relay_cell(): 30: end cell (closed normally) for stream 1935. Removing stream. Dec 19 12:33:56.352 [info] connection_dir_client_reached_eof(): Uploading rendezvous descriptor: finished with status 200 ("Service descriptor stored") Dec 19 12:33:56.352 [info] connection_edge_process_relay_cell(): 34: end cell (closed normally) for stream 1937. Removing stream. Dec 19 12:33:56.352 [info] connection_edge_process_relay_cell(): 32: end cell (closed normally) for stream 1936. Removing stream. Dec 19 12:33:56.352 [info] connection_edge_process_relay_cell(): 36: end cell (closed normally) for stream 1938. Removing stream. Dec 19 12:33:56.352 [info] connection_dir_client_reached_eof(): Uploading rendezvous descriptor: finished with status 200 ("Service descriptor stored") Dec 19 12:33:56.353 [info] connection_dir_client_reached_eof(): Uploading rendezvous descriptor: finished with status 200 ("Service descriptor stored") Dec 19 12:33:56.353 [info] connection_dir_client_reached_eof(): Uploading rendezvous descriptor: finished with status 200 ("Service descriptor stored") Dec 19 12:34:03.628 [info] rend_service_introduce(): Received INTRODUCE2 cell for service upxlw4s7cpagkusq on circ 51740. Dec 19 12:34:03.635 [info] circuit_launch_by_extend_info(): Cannibalizing circ 'tor22' for purpose 15 Dec 19 12:34:03.637 [info] rend_service_introduce(): Accepted intro; launching circuit to 'tor19' (cookie 2952EE7E) for service upxlw4s7cpagkusq. Dec 19 12:34:03.647 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:34:03.647 [info] internal (high-uptime) circ (length 4, exit tor19): tor30(open) tor8(open) tor22(open) tor19(open) Dec 19 12:34:03.647 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:34:03.647 [info] rend_service_rendezvous_has_opened(): Done building circuit 42698 to rendezvous with cookie 2952EE7E for service upxlw4s7cpagkusq Dec 19 12:34:04.343 [info] circuit_predict_and_launch_new(): Have 3 clean circs (2 internal), need another internal circ for my hidden service. Dec 19 12:34:04.347 [info] circuit_send_next_onion_skin(): First hop: finished sending CREATE cell to 'tor8' Dec 19 12:34:04.355 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:34:04.355 [info] internal (high-uptime) circ (length 3, exit tor1): tor8(open) tor31(closed) tor1(closed) Dec 19 12:34:04.366 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:34:04.366 [info] internal (high-uptime) circ (length 3, exit tor1): tor8(open) tor31(open) tor1(closed) Dec 19 12:34:04.378 [info] circuit_finish_handshake(): Finished building circuit hop: Dec 19 12:34:04.378 [info] internal (high-uptime) circ (length 3, exit tor1): tor8(open) tor31(open) tor1(open) Dec 19 12:34:04.378 [info] circuit_send_next_onion_skin(): circuit built! Dec 19 12:34:04.482 [info] connection_edge_finished_connecting(): Exit connection to (rendezvous):80 (141.201.27.14) established. Dec 19 12:34:04.589 [info] connection_edge_process_relay_cell(): 30: end cell (closed normally) for stream 59882. Removing stream. Dec 19 12:34:22.640 [info] connection_edge_finished_connecting(): Exit connection to (rendezvous):80 (141.201.27.14) established. Dec 19 12:34:23.045 [info] connection_edge_process_relay_cell(): 30: end cell (closed normally) for stream 59883. Removing stream. Dec 19 12:34:38.304 [info] circuit_extend(): Next router (127.0.0.10:19010) not connected. Connecting. Dec 19 12:34:47.280 [info] connection_control_process_inbuf_v0(): Detected v1 control protocol on connection (fd 33) Dec 19 12:34:47.280 [info] handle_control_authenticate(): Authenticated control connection (33) Dec 19 12:34:47.280 [err] signal_callback(): Catching signal TERM, exiting cleanly. Dec 19 12:34:47.438 [info] dnsworker_main(): DNS worker exiting because Tor process closed connection (either pruned idle dnsworker or died).
-
For my own reference, a list of cores with this error type.
Tor build C,
./tor-create-and-go-away-40/core.15110.delete_log ./tor-create-and-go-away-40/core.10553.delete_log ./tor-create-and-go-away-40/core.31487.delete_log ./tor-create-and-go-away-40/core.30076.delete_log ./tor-create-and-go-away-40/core.5372.delete_log ./tor-create-and-go-away-41/core.17708.delete_log ./tor-create-and-go-away-41/core.1913.delete_log ./tor-create-and-go-away-41/core.2301.delete_log ./tor-create-and-go-away-41/core.24664.delete_log ./tor-create-and-go-away-41/core.7266.delete_log ./tor-create-and-go-away-41/core.26522.delete_log ./tor-create-and-go-away-41/core.28730.delete_log ./tor-create-and-go-away-41/core.19063.delete_log ./tor-create-and-go-away-42/core.26779.delete_log ./tor-create-and-go-away-42/core.5194.delete_log ./tor-create-and-go-away-43/core.13189.delete_log ./tor-create-and-go-away-43/core.22063.delete_log ./tor-create-and-go-away-43/core.23322.delete_log ./tor-create-and-go-away-43/core.16203.delete_log ./tor-create-and-go-away-44/core.2352.delete_log ./tor-create-and-go-away-44/core.28049.delete_log ./tor-create-and-go-away-44/core.11547.delete_log ./tor-create-and-go-away-44/core.22907.delete_log ./tor-create-and-go-away-44/core.30032.delete_log ./tor-create-and-go-away-44/core.31319.delete_log ./tor-create-and-go-away-44/core.8491.delete_log ./tor-create-and-go-away-44/core.27423.delete_log ./tor-create-and-go-away-44/core.30319.delete_log ./tor-create-and-go-away-44/core.13356.delete_log ./tor-create-and-go-away-44/core.29507.delete_log ./tor-create-and-go-away-44/core.32105.delete_log ./tor-create-and-go-away-44/core.7856.delete_log ./tor-create-and-go-away-44/core.13437.delete_log ./tor-create-and-go-away-44/core.11668.delete_log ./tor-create-and-go-away-44/core.26207.delete_log ./tor-create-and-go-away-45/core.5993.delete_log ./tor-create-and-go-away-45/core.21358.delete_log ./tor-create-and-go-away-45/core.11499.delete_log ./tor-create-and-go-away-45/core.15661.delete_log ./tor-create-and-go-away-45/core.18636.delete_log ./tor-create-and-go-away-46/core.29983.delete_log ./tor-create-and-go-away-46/core.5086.delete_log ./tor-create-and-go-away-46/core.3580.delete_log ./tor-create-and-go-away-47/core.26033.delete_log ./tor-create-and-go-away-47/core.21237.delete_log ./tor-create-and-go-away-47/core.29383.delete_log
I just experienced this running 0.1.1.20 as a server. When I !^c'ed, I got:
log.c:342 delete_log: Assertion tmpl failed; aborting.
#0 0x0000002a95e43545 in raise () from /lib/libc.so.6 #1 0x0000002a95e44cce in abort () from /lib/libc.so.6 #2 (closed) 0x0000000000451b5b in delete_log (victim=0x5bada0) at log.c:348 #3 (closed) 0x000000000045189b in logv (severity=6, domain=32768, funcname=0x47115d "cpuworker_main", format=0x471580 "CPU worker exiting because Tor process closed connection (either rotated keys or died).", ap=0x41fff430) at log.c:228 #4 (closed) 0x0000000000451a0f in _log_fn (severity=31779, domain=31783, fn=0x6 <Address 0x6 out of bounds>, format=0xffffffffffffffff <Address 0xffffffffffffffff out of bounds>) at log.c:252 #5 (closed) 0x000000000042a498 in cpuworker_main (data=0x7c23) at cpuworker.c:297 #6 (closed) 0x0000000000456040 in tor_pthread_helper_fn (_data=0x7c23) at compat.c:833 #7 (closed) 0x0000002a95af8b55 in start_thread () from /lib/libpthread.so.0 #8 (closed) 0x0000002a95ee67f0 in clone () from /lib/libc.so.6
I just applied a minor patch to make this part more resilient to bugs. In general, it looks like we're going to have to put a mutex around some of our log stuff, since it's shared between threads.
mentioned in issue #358 (moved)
moved to tpo/core/tor#222 (closed)
mentioned in issue tpo/core/tor#358 (closed)
