[Author Prev][Author Next][Thread Prev][Thread Next][Author Index][Thread Index]

Re: [tor-bugs] #16013 [Tor]: Assertion ENTRY_TO_CONN(conn)->state == AP_CONN_STATE_CIRCUIT_WAIT failed in circuit_get_open_circ_or_launch at circuituse.c:1835

Subject: Re: [tor-bugs] #16013 [Tor]: Assertion ENTRY_TO_CONN(conn)->state == AP_CONN_STATE_CIRCUIT_WAIT failed in circuit_get_open_circ_or_launch at circuituse.c:1835
From: "Tor Bug Tracker & Wiki" <blackhole@xxxxxxxxxxxxxx>
Date: Sun, 21 Jun 2015 23:31:09 -0000
Auto-submitted: auto-generated
Delivered-to: archiver@xxxxxxxx
Delivery-date: Sun, 21 Jun 2015 19:31:18 -0400
In-reply-to: <051.b4e6bd0b807841e339290e88c94ebe94@xxxxxxxxxxxxxx>
List-archive: <http://lists.torproject.org/pipermail/tor-bugs/>
List-help: <mailto:tor-bugs-request@lists.torproject.org?subject=help>
List-id: "auto: Tor bug tracker status mails" <tor-bugs.lists.torproject.org>
List-post: <mailto:tor-bugs@lists.torproject.org>
List-subscribe: <https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs>, <mailto:tor-bugs-request@lists.torproject.org?subject=subscribe>
List-unsubscribe: <https://lists.torproject.org/cgi-bin/mailman/options/tor-bugs>, <mailto:tor-bugs-request@lists.torproject.org?subject=unsubscribe>
References: <051.b4e6bd0b807841e339290e88c94ebe94@xxxxxxxxxxxxxx>
Reply-to: tor-assistants@xxxxxxxxxxxxxx
Sender: "tor-bugs" <tor-bugs-bounces@xxxxxxxxxxxxxxxxxxxx>

#16013: Assertion ENTRY_TO_CONN(conn)->state == AP_CONN_STATE_CIRCUIT_WAIT failed
in circuit_get_open_circ_or_launch at circuituse.c:1835
-----------------------------+-------------------------------------
     Reporter:  cypherpunks  |      Owner:
         Type:  defect       |     Status:  needs_information
     Priority:  normal       |  Milestone:  Tor: 0.2.7.x-final
    Component:  Tor          |    Version:  Tor: unspecified
   Resolution:               |   Keywords:  regression 026-backport
Actual Points:               |  Parent ID:
       Points:               |
-----------------------------+-------------------------------------

Comment (by starlight):

 100% reproducible

 {{{
 [err] circuit_get_open_circ_or_launch(): Bug: Connection state mismatch:
 wanted AP_CONN_STATE_CIRCUIT_WAIT, but got 6 (waiting for rendezvous desc)
 }}}

 {{{
 Jun 21 19:22:52.000 [debug] conn_write_callback(): socket 12 wants to
 write.
 Jun 21 19:22:53.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:53.000 [info] connection_ap_handshake_attach_circuit(): Intro
 circ 3044306830 present and awaiting ack (rend 3615842360). Stalling.
 (stream 7 sec old)
 Jun 21 19:22:53.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:53.000 [info] connection_ap_handshake_attach_circuit(): Intro
 circ 3044306830 present and awaiting ack (rend 3615842360). Stalling.
 (stream 7 sec old)
 Jun 21 19:22:53.000 [debug] conn_write_callback(): socket 12 wants to
 write.
 Jun 21 19:22:54.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:54.000 [info] connection_ap_handshake_attach_circuit(): Intro
 circ 3044306830 present and awaiting ack (rend 3615842360). Stalling.
 (stream 8 sec old)
 Jun 21 19:22:54.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:54.000 [info] connection_ap_handshake_attach_circuit(): Intro
 circ 3044306830 present and awaiting ack (rend 3615842360). Stalling.
 (stream 8 sec old)
 Jun 21 19:22:54.000 [debug] conn_write_callback(): socket 12 wants to
 write.
 Jun 21 19:22:55.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:55.000 [info] connection_ap_handshake_attach_circuit(): Intro
 circ 3044306830 present and awaiting ack (rend 3615842360). Stalling.
 (stream 9 sec old)
 Jun 21 19:22:55.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:55.000 [info] connection_ap_handshake_attach_circuit(): Intro
 circ 3044306830 present and awaiting ack (rend 3615842360). Stalling.
 (stream 9 sec old)
 Jun 21 19:22:55.000 [debug] conn_write_callback(): socket 12 wants to
 write.
 Jun 21 19:22:56.000 [debug] conn_read_callback(): socket 12 wants to read.
 Jun 21 19:22:56.000 [debug] read_to_chunk(): Read 15 bytes. 15 on inbuf.
 Jun 21 19:22:56.000 [info] rend_cache_purge(): Purging HS descriptor cache
 Jun 21 19:22:56.000 [info] rend_client_purge_last_hid_serv_requests():
 Purging client last-HS-desc-request-time table
 Jun 21 19:22:56.000 [debug] conn_write_callback(): socket 12 wants to
 write.
 Jun 21 19:22:56.000 [debug] circuit_find_to_cannibalize(): Hunting for a
 circ to cannibalize: purpose 9, uptime 0, capacity 1, internal 1
 Jun 21 19:22:56.000 [info] circuit_launch_by_extend_info(): Cannibalizing
 circ 'AAAPolicy' for purpose 9 (Hidden service client: Establishing
 rendezvous point)
 Jun 21 19:22:56.000 [debug] circuit_change_purpose(): changing purpose of
 origin circ 48 from "General-purpose client" (5) to "Hidden service
 client: Establishing rendezvous point" (9)
 Jun 21 19:22:56.000 [info] rend_client_rendcirc_has_opened(): rendcirc is
 open
 Jun 21 19:22:56.000 [info] rend_client_send_establish_rendezvous():
 Sending an ESTABLISH_RENDEZVOUS cell
 Jun 21 19:22:56.000 [debug] pathbias_count_use_attempt(): Marked circuit
 48 (7.000000/15.000000) as used for guard Pascal8
 ($7B2553AEA4A3FC9E1B513D772ECA652C8CC15337).
 Jun 21 19:22:56.000 [debug] relay_send_command_from_edge_(): delivering 33
 cell forward.
 Jun 21 19:22:56.000 [debug] relay_send_command_from_edge_(): Sending a
 RELAY_EARLY cell; 4 remaining.
 Jun 21 19:22:56.000 [debug] circuit_package_relay_cell(): crypting a layer
 of the relay cell.
 Jun 21 19:22:56.000 [debug] circuit_package_relay_cell(): crypting a layer
 of the relay cell.
 Jun 21 19:22:56.000 [debug] circuit_package_relay_cell(): crypting a layer
 of the relay cell.
 Jun 21 19:22:56.000 [debug] append_cell_to_circuit_queue(): Made a circuit
 active.
 Jun 21 19:22:56.000 [debug] scheduler_channel_has_waiting_cells(): Channel
 0 at 0x614000087240 went from waiting_for_cells to pending
 Jun 21 19:22:56.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:56.000 [warn] Query '[scrubbed]' didn't have valid rend desc
 in cache. Failing.
 Jun 21 19:22:56.000 [info] circuit_get_open_circ_or_launch(): No intro
 points for '[scrubbed]': re-fetching service descriptor.
 Jun 21 19:22:56.000 [debug] rend_client_refetch_v2_renddesc(): Fetching v2
 rendezvous descriptor for service [scrubbed]
 Jun 21 19:22:56.000 [debug] directory_initiate_command_rend(): anonymized
 1, use_begindir 1.
 Jun 21 19:22:56.000 [debug] directory_initiate_command_rend(): Initiating
 hidden-service v2 descriptor fetch
 Jun 21 19:22:56.000 [info] connection_ap_make_link(): Making internal
 anonymized tunnel to [scrubbed]:9001 ...
 Jun 21 19:22:56.000 [debug] connection_add_impl(): new conn type Socks,
 socket -1, address (Tor_internal), n_conns 10.
 Jun 21 19:22:56.000 [debug] extend_info_from_node(): using
 141.255.189.161:9001 for OxylEpsilon
 Jun 21 19:22:56.000 [debug] circuit_find_to_cannibalize(): Hunting for a
 circ to cannibalize: purpose 5, uptime 0, capacity 1, internal 1
 Jun 21 19:22:56.000 [info] circuit_launch_by_extend_info(): Cannibalizing
 circ 'redjohn1' for purpose 5 (General-purpose client)
 Jun 21 19:22:56.000 [debug] circuit_send_next_onion_skin(): starting to
 send subsequent skin.
 Jun 21 19:22:56.000 [info] circuit_send_next_onion_skin(): Sending extend
 relay cell.
 Jun 21 19:22:56.000 [debug] relay_send_command_from_edge_(): delivering 14
 cell forward.
 Jun 21 19:22:56.000 [debug] relay_send_command_from_edge_(): Sending a
 RELAY_EARLY cell; 5 remaining.
 Jun 21 19:22:56.000 [debug] circuit_package_relay_cell(): crypting a layer
 of the relay cell.
 Jun 21 19:22:56.000 [debug] circuit_package_relay_cell(): crypting a layer
 of the relay cell.
 Jun 21 19:22:56.000 [debug] circuit_package_relay_cell(): crypting a layer
 of the relay cell.
 Jun 21 19:22:56.000 [debug] append_cell_to_circuit_queue(): Made a circuit
 active.
 Jun 21 19:22:56.000 [debug] scheduler_channel_has_waiting_cells(): Channel
 1 at 0x614000086440 went from waiting_for_cells to pending
 Jun 21 19:22:56.000 [info] connection_ap_make_link(): ... application
 connection created and linked.
 Jun 21 19:22:56.000 [debug] connection_add_impl(): new conn type
 Directory, socket -1, address 141.255.189.161, n_conns 11.
 Jun 21 19:22:56.000 [info] directory_get_from_hs_dir(): Sending fetch
 request for v2 descriptor for service 'v4sciq74tvcydqip' with descriptor
 ID 'soxxwg56bxmusmbapm2uc2xay527nole', auth type 0, and descriptor cookie
 '[none]' to hidden service directory
 $93C3E9A094D9B3F01785DB7580101F93D8D19A89~OxylEpsilon at 141.255.189.161
 Jun 21 19:22:56.000 [info] connection_ap_handshake_attach_circuit(): Intro
 (0) and rend (3216239652) circs are not both ready. Stalling conn. (10 sec
 old)
 Jun 21 19:22:56.000 [debug] circuit_get_open_circ_or_launch(): one on the
 way!
 Jun 21 19:22:56.000 [warn] Query '[scrubbed]' didn't have valid rend desc
 in cache. Failing.
 Jun 21 19:22:56.000 [info] circuit_get_open_circ_or_launch(): No intro
 points for '[scrubbed]': re-fetching service descriptor.
 Jun 21 19:22:56.000 [debug] rend_client_refetch_v2_renddesc(): Fetching v2
 rendezvous descriptor for service [scrubbed]
 Jun 21 19:22:56.000 [debug] directory_initiate_command_rend(): anonymized
 1, use_begindir 1.
 Jun 21 19:22:56.000 [debug] directory_initiate_command_rend(): Initiating
 hidden-service v2 descriptor fetch
 Jun 21 19:22:56.000 [info] connection_ap_make_link(): Making internal
 anonymized tunnel to [scrubbed]:9001 ...
 Jun 21 19:22:56.000 [debug] connection_add_impl(): new conn type Socks,
 socket -1, address (Tor_internal), n_conns 12.
 Jun 21 19:22:56.000 [debug] extend_info_from_node(): using
 85.228.195.5:9001 for hashmaps
 Jun 21 19:22:56.000 [debug] circuit_find_to_cannibalize(): Hunting for a
 circ to cannibalize: purpose 5, uptime 0, capacity 1, internal 1
 Jun 21 19:22:56.000 [debug] new_route_len(): Chosen route length 4
 (6629/6629 routers suitable).
 Jun 21 19:22:56.000 [info] onion_pick_cpath_exit(): Using requested exit
 node '$943CE107D30C653BC4CAF3840006DB8D1BCA6B29~hashmaps at 85.228.195.5'
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Path is 0 long; we want
 4
 Jun 21 19:22:56.000 [debug] extend_info_from_node(): using
 23.254.166.222:80 for Pascal8
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Chose router
 $7B2553AEA4A3FC9E1B513D772ECA652C8CC15337~Pascal8 at 23.254.166.222 for
 hop 1 (exit is hashmaps)
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Path is 1 long; we want
 4
 Jun 21 19:22:56.000 [debug] choose_good_middle_server(): Contemplating
 intermediate hop 1: random choice.
 Jun 21 19:22:56.000 [debug] router_choose_random_node(): We found 5770
 running nodes.
 Jun 21 19:22:56.000 [debug] router_choose_random_node(): We removed 0
 excludednodes, leaving 5770 nodes.
 Jun 21 19:22:56.000 [debug] router_choose_random_node(): We removed 16
 excludedsmartlist, leaving 5757 nodes.
 Jun 21 19:22:56.000 [debug] compute_weighted_bandwidths(): Generated
 weighted bandwidths for rule weight as middle node based on weights
 Wg=0.408700 Wm=1.000000 We=0.000000 Wd=0.000000 with total bw 0
 Jun 21 19:22:56.000 [debug] extend_info_from_node(): using 5.9.158.68:9001
 for freespeech4thedumb1
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Chose router
 $7E2F94EA9214EC6CD05A0FC1BA51A0FA30FC83C7~freespeech4thedumb1 at
 5.9.158.68 for hop 2 (exit is hashmaps)
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Path is 2 long; we want
 4
 Jun 21 19:22:56.000 [debug] choose_good_middle_server(): Contemplating
 intermediate hop 2: random choice.
 Jun 21 19:22:56.000 [debug] router_choose_random_node(): We found 5770
 running nodes.
 Jun 21 19:22:56.000 [debug] router_choose_random_node(): We removed 0
 excludednodes, leaving 5770 nodes.
 Jun 21 19:22:56.000 [debug] router_choose_random_node(): We removed 62
 excludedsmartlist, leaving 5714 nodes.
 Jun 21 19:22:56.000 [debug] compute_weighted_bandwidths(): Generated
 weighted bandwidths for rule weight as middle node based on weights
 Wg=0.408700 Wm=1.000000 We=0.000000 Wd=0.000000 with total bw 0
 Jun 21 19:22:56.000 [debug] extend_info_from_node(): using
 213.136.71.21:9001 for maltimore
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Chose router
 $78C4FCE0851C99A4E05563C6F520C68F28BD916E~maltimore at 213.136.71.21 for
 hop 3 (exit is hashmaps)
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Path is 3 long; we want
 4
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Chose router
 $943CE107D30C653BC4CAF3840006DB8D1BCA6B29~hashmaps at 85.228.195.5 for hop
 4 (exit is hashmaps)
 Jun 21 19:22:56.000 [debug] onion_extend_cpath(): Path is complete: 4
 steps long
 Jun 21 19:22:56.000 [debug] circuit_handle_first_hop(): Looking for
 firsthop '23.254.166.222:80'
 Jun 21 19:22:56.000 [debug] circuit_handle_first_hop(): Conn open.
 Delivering first onion skin.
 Jun 21 19:22:56.000 [debug] circuit_send_next_onion_skin(): First skin;
 sending create cell.
 Jun 21 19:22:56.000 [debug] circuit_get_by_circid_channel_impl():
 circuit_get_by_circid_channel_impl() found nothing for circ_id 2423611392,
 channel ID 0 (0x614000087240)
 Jun 21 19:22:56.000 [debug] circuit_deliver_create_cell(): Chosen circID
 2423611392.
 Jun 21 19:22:56.000 [debug] circuitmux_attach_circuit(): Attaching circuit
 2423611392 on channel 0 to cmux 0x6080000d7c20
 Jun 21 19:22:56.000 [debug] append_cell_to_circuit_queue(): Made a circuit
 active.
 Jun 21 19:22:56.000 [info] circuit_send_next_onion_skin(): First hop:
 finished sending CREATE cell to
 '$7B2553AEA4A3FC9E1B513D772ECA652C8CC15337~Pascal8 at 23.254.166.222'
 Jun 21 19:22:56.000 [info] connection_ap_make_link(): ... application
 connection created and linked.
 Jun 21 19:22:56.000 [debug] connection_add_impl(): new conn type
 Directory, socket -1, address 85.228.195.5, n_conns 13.
 Jun 21 19:22:56.000 [info] directory_get_from_hs_dir(): Sending fetch
 request for v2 descriptor for service 'v4sciq74tvcydqip' with descriptor
 ID 'soxxwg56bxmusmbapm2uc2xay527nole', auth type 0, and descriptor cookie
 '[none]' to hidden service directory
 $943CE107D30C653BC4CAF3840006DB8D1BCA6B29~hashmaps at 85.228.195.5
 Jun 21 19:22:56.000 [info] connection_ap_handshake_attach_circuit(): Intro
 (0) and rend (3216239652) circs are not both ready. Stalling conn. (10 sec
 old)
 Jun 21 19:22:56.000 [err] circuit_get_open_circ_or_launch(): Bug:
 Connection state mismatch: wanted AP_CONN_STATE_CIRCUIT_WAIT, but got 6
 (waiting for rendezvous desc)
 Jun 21 19:22:56.000 [err] tor_assertion_failed_(): Bug:
 src/or/circuituse.c:1841: circuit_get_open_circ_or_launch: Assertion
 ENTRY_TO_CONN(conn)->state == AP_CONN_STATE_CIRCUIT_WAIT failed; aborting.
 Jun 21 19:22:56.000 [err] Bug: Assertion ENTRY_TO_CONN(conn)->state ==
 AP_CONN_STATE_CIRCUIT_WAIT failed in circuit_get_open_circ_or_launch at
 src/or/circuituse.c:1841. Stack trace:
 Jun 21 19:22:56.000 [err] Bug:
 /usr/local/lib64/libasan.so.1(__interceptor_backtrace+0x3a)
 [0x2b1b9500712a]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(log_backtrace+0x43) [0x2b1b945aac9d]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(tor_assertion_failed_+0xf6)
 [0x2b1b945d15df]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b944a488b]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(connection_ap_handshake_attach_circuit+0x9bf)
 [0x2b1b944a6ac5]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(connection_ap_attach_pending+0x1d2)
 [0x2b1b944f9680]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(circuit_build_needed_circs+0x30)
 [0x2b1b944a450b]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b94343218]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b94343a52]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b94615215]
 Jun 21 19:22:56.000 [err] Bug:
 /usr/local/lib64/libevent-2.0.so.5(event_base_loop+0x7e6) [0x2b1b96145066]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b94339d24]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b94339ec9]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(do_main_loop+0x356) [0x2b1b943445a8]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(tor_main+0x1aa) [0x2b1b94345c8e]
 Jun 21 19:22:56.000 [err] Bug:
 /w/gpl/tor-0.2.6.9-asus/src/or/tor(main+0x19) [0x2b1b94339289]
 Jun 21 19:22:56.000 [err] Bug:
 /lib64/libc.so.6(__libc_start_main+0xf4) [0x2b1b97f8d9f4]
 Jun 21 19:22:56.000 [err] Bug:     /w/gpl/tor-0.2.6.9-asus/src/or/tor
 [0x2b1b94339149]
 }}}

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/16013#comment:19>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online
_______________________________________________
tor-bugs mailing list
tor-bugs@xxxxxxxxxxxxxxxxxxxx
https://lists.torproject.org/cgi-bin/mailman/listinfo/tor-bugs

Prev by Author: Re: [tor-bugs] #16327 [Tor Browser]: NavigatorLanguage API should be spoofed
Next by Author: [tor-bugs] #16413 [Tor Browser]: tor.service only connects by Tor Browser Settings
Previous by thread: Re: [tor-bugs] #16013 [Tor]: Assertion ENTRY_TO_CONN(conn)->state == AP_CONN_STATE_CIRCUIT_WAIT failed in circuit_get_open_circ_or_launch at circuituse.c:1835
Next by thread: Re: [tor-bugs] #16013 [Tor]: Assertion ENTRY_TO_CONN(conn)->state == AP_CONN_STATE_CIRCUIT_WAIT failed in circuit_get_open_circ_or_launch at circuituse.c:1835
Index(es):
- Author
- Thread