[tor-bugs] #24972 [Core Tor/Tor]: Bug: src/or/hs_descriptor.c:2357: hs_desc_encode_descriptor: Non-fatal assertion !(ret < 0) failed.
Tor Bug Tracker & Wiki
blackhole at torproject.org
Tue Jan 23 08:23:26 UTC 2018
#24972: Bug: src/or/hs_descriptor.c:2357: hs_desc_encode_descriptor: Non-fatal
assertion !(ret < 0) failed.
----------------------------+------------------------------------
Reporter: asn | Owner: (none)
Type: defect | Status: new
Priority: Medium | Milestone: Tor: 0.3.3.x-final
Component: Core Tor/Tor | Version:
Severity: Normal | Resolution:
Keywords: tor-hs prop224 | Actual Points:
Parent ID: | Points: 2
Reviewer: | Sponsor:
----------------------------+------------------------------------
Description changed by asn:
Old description:
> My HSv3 is unable to encode its own descriptor with the following fail:
> {{{
> Jan 21 08:00:49.000 [info] connection_free_minimal(): Freeing linked
> Socks connection [open] with 0 bytes on inbuf, 0 on outbuf.
> Jan 21 08:00:49.000 [info] handle_response_upload_hsdesc(): Uploaded
> hidden service descriptor (status 200 ("HS descriptor stored
> successfully."))
> Jan 21 08:00:49.000 [info] handle_response_upload_hsdesc(): Uploading
> hidden service descriptor: finished with status 200 ("HS descriptor
> stored successfully.")
> Jan 21 08:00:49.000 [info] connection_free_minimal(): Freeing linked
> Directory connection [client finished] with 0 bytes on inbuf, 0 on
> outbuf.
> Jan 21 08:00:49.000 [info] circuit_finish_handshake(): Finished building
> circuit hop:
> Jan 21 08:00:49.000 [info] internal (high-uptime) circ (length 4, last
> hop damita): $E2920D7419B7601CF82D43400D042DA70E0675B2(open)
> $CA58EB617C6CA2F351AEFD56C84B8A7AF7704B22(open)
> $0E3D3FCE26F6969B7AE80E4CA6C4CFA97988F31E(open)
> $A9F7185499C5784E35B5C25744ED4AB75437CE5D(open)
> Jan 21 08:00:49.000 [info] entry_guards_note_guard_success(): Recorded
> success for primary confirmed guard papadouka
> ($E2920D7419B7601CF82D43400D042DA70E0675B2)
> Jan 21 08:00:49.000 [info] circuit_build_no_more_hops(): circuit built!
> Jan 21 08:00:49.000 [info] pathbias_count_build_success(): Got success
> count 224.332749/291.637758 for guard papadouka
> ($E2920D7419B7601CF82D43400D042DA70E0675B2)
> Jan 21 08:01:06.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 5296 ms. Delta -4ms
> Jan 21 08:01:12.000 [info] routerlist_remove_old_routers(): We have 0
> live routers and 0 old router descriptors.
> Jan 21 08:01:19.000 [info] or_state_save(): Saved state to
> "/home/f/.tor/state"
> Jan 21 08:01:25.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 5996 ms. Delta 2ms
> Jan 21 08:01:32.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 6840 ms. Delta -2ms
> Jan 21 08:01:43.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 2096 ms. Delta 0ms
> Jan 21 08:01:51.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 7912 ms. Delta 0ms
> Jan 21 08:01:57.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 6456 ms. Delta 0ms
> Jan 21 08:02:05.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 7952 ms. Delta 3ms
> Jan 21 08:02:07.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 2280 ms. Delta 1ms
> Jan 21 08:02:12.000 [info] routerlist_remove_old_routers(): We have 0
> live routers and 0 old router descriptors.
> Jan 21 08:02:20.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 3756 ms. Delta 2ms
> Jan 21 08:02:33.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 8344 ms. Delta 0ms
> Jan 21 08:03:00.000 [info]
> channelpadding_send_padding_cell_for_callback(): Sending netflow
> keepalive on 58 to 86.106.137.6:443
> (E2920D7419B7601CF82D43400D042DA70E0675B2) after 4508 ms. Delta 2ms
> Jan 21 08:03:04.000 [info] run_upload_descriptor_event(): Initiating
> upload for hidden service current descriptor for service
> j2eiu2izwjpazjevu4xs3muaif3jzex3nnvnu677vz2fypmzccvhhiid with 3/3
> introduction points.
> Jan 21 08:03:04.000 [info] close_directory_connections(): Closed 0 active
> service directory connections for descriptor
> 9btQxrMpxWDJwnf1TU6U+5vcPmPdD2OPBVAKKmRLr7I of service
> j2eiu2izwjpazjevu4xs3muaif3jzex3nnvnu677vz2fypmzccvhhiid
> Jan 21 08:03:04.000 [info] crypto_strongest_rand_fallback(): Reading
> entropy from "/dev/urandom"
> Jan 21 08:03:04.000 [info] crypto_strongest_rand_fallback(): Reading
> entropy from "/dev/urandom"
> Jan 21 08:03:04.000 [warn] Invalid signature for service descriptor
> signing key.
> Jan 21 08:03:04.000 [warn] tor_bug_occurred_(): Bug:
> src/or/hs_descriptor.c:2357: hs_desc_encode_descriptor: Non-fatal
> assertion !(ret < 0) failed. (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
> Jan 21 08:03:04.000 [warn] Bug: Non-fatal assertion !(ret < 0) failed in
> hs_desc_encode_descriptor at src/or/hs_descriptor.c:2357. Stack trace:
> (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
> Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(log_backtrace+0x42)
> [0x7ffa9cd66ac2] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
> Jan 21 08:03:04.000 [warn] Bug:
> ./tor/src/or/tor(tor_bug_occurred_+0xb7) [0x7ffa9cd81cd7] (on Tor 0.3.3.0
> -alpha-dev d69c8f7117a5975a)
> Jan 21 08:03:04.000 [warn] Bug:
> ./tor/src/or/tor(hs_desc_encode_descriptor+0xb2) [0x7ffa9cd4d782] (on Tor
> 0.3.3.0-alpha-dev d69c8f7117a5975a)
> Jan 21 08:03:04.000 [warn] Bug:
> ./tor/src/or/tor(hs_service_run_scheduled_events+0x21f3) [0x7ffa9cd570d3]
> (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
> Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(+0x4ca31)
> [0x7ffa9cc30a31] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
> }}}
>
> That started happening 4 days after I started up Tor and it persists up
> to today: my HS is still unable to create its own desc...
>
> FWIW, the only difference from the past is that I've been using vanguards
> but that should not influence the signing of the desc....
New description:
My HSv3 is unable to encode its own descriptor with the following fail:
{{{
Jan 21 08:00:49.000 [info] connection_free_minimal(): Freeing linked Socks
connection [open] with 0 bytes on inbuf, 0 on outbuf.
Jan 21 08:00:49.000 [info] handle_response_upload_hsdesc(): Uploaded
hidden service descriptor (status 200 ("HS descriptor stored
successfully."))
Jan 21 08:00:49.000 [info] handle_response_upload_hsdesc(): Uploading
hidden service descriptor: finished with status 200 ("HS descriptor stored
successfully.")
Jan 21 08:00:49.000 [info] connection_free_minimal(): Freeing linked
Directory connection [client finished] with 0 bytes on inbuf, 0 on outbuf.
Jan 21 08:00:49.000 [info] circuit_finish_handshake(): Finished building
circuit hop:
Jan 21 08:00:49.000 [info] internal (high-uptime) circ (length 4, last hop
damita): $E2920D7419B7601CF82D43400D042DA70E0675B2(open)
$CA58EB617C6CA2F351AEFD56C84B8A7AF7704B22(open)
$0E3D3FCE26F6969B7AE80E4CA6C4CFA97988F31E(open)
$A9F7185499C5784E35B5C25744ED4AB75437CE5D(open)
Jan 21 08:00:49.000 [info] entry_guards_note_guard_success(): Recorded
success for primary confirmed guard papadouka
($E2920D7419B7601CF82D43400D042DA70E0675B2)
Jan 21 08:00:49.000 [info] circuit_build_no_more_hops(): circuit built!
Jan 21 08:00:49.000 [info] pathbias_count_build_success(): Got success
count 224.332749/291.637758 for guard papadouka
($E2920D7419B7601CF82D43400D042DA70E0675B2)
Jan 21 08:01:06.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
5296 ms. Delta -4ms
Jan 21 08:01:12.000 [info] routerlist_remove_old_routers(): We have 0 live
routers and 0 old router descriptors.
Jan 21 08:01:19.000 [info] or_state_save(): Saved state to
"/home/f/.tor/state"
Jan 21 08:01:25.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
5996 ms. Delta 2ms
Jan 21 08:01:32.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
6840 ms. Delta -2ms
Jan 21 08:01:43.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
2096 ms. Delta 0ms
Jan 21 08:01:51.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
7912 ms. Delta 0ms
Jan 21 08:01:57.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
6456 ms. Delta 0ms
Jan 21 08:02:05.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
7952 ms. Delta 3ms
Jan 21 08:02:07.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
2280 ms. Delta 1ms
Jan 21 08:02:12.000 [info] routerlist_remove_old_routers(): We have 0 live
routers and 0 old router descriptors.
Jan 21 08:02:20.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
3756 ms. Delta 2ms
Jan 21 08:02:33.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
8344 ms. Delta 0ms
Jan 21 08:03:00.000 [info]
channelpadding_send_padding_cell_for_callback(): Sending netflow keepalive
on 58 to 86.106.137.6:443 (E2920D7419B7601CF82D43400D042DA70E0675B2) after
4508 ms. Delta 2ms
Jan 21 08:03:04.000 [info] run_upload_descriptor_event(): Initiating
upload for hidden service current descriptor for service
j2eiu2izwjpazjevu4xs3muaif3jzex3nnvnu677vz2fypmzccvhhiid with 3/3
introduction points.
Jan 21 08:03:04.000 [info] close_directory_connections(): Closed 0 active
service directory connections for descriptor
9btQxrMpxWDJwnf1TU6U+5vcPmPdD2OPBVAKKmRLr7I of service
j2eiu2izwjpazjevu4xs3muaif3jzex3nnvnu677vz2fypmzccvhhiid
Jan 21 08:03:04.000 [info] crypto_strongest_rand_fallback(): Reading
entropy from "/dev/urandom"
Jan 21 08:03:04.000 [info] crypto_strongest_rand_fallback(): Reading
entropy from "/dev/urandom"
Jan 21 08:03:04.000 [warn] Invalid signature for service descriptor
signing key.
Jan 21 08:03:04.000 [warn] tor_bug_occurred_(): Bug:
src/or/hs_descriptor.c:2357: hs_desc_encode_descriptor: Non-fatal
assertion !(ret < 0) failed. (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: Non-fatal assertion !(ret < 0) failed in
hs_desc_encode_descriptor at src/or/hs_descriptor.c:2357. Stack trace: (on
Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(log_backtrace+0x42)
[0x7ffa9cd66ac2] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug:
./tor/src/or/tor(tor_bug_occurred_+0xb7) [0x7ffa9cd81cd7] (on Tor 0.3.3.0
-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug:
./tor/src/or/tor(hs_desc_encode_descriptor+0xb2) [0x7ffa9cd4d782] (on Tor
0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug:
./tor/src/or/tor(hs_service_run_scheduled_events+0x21f3) [0x7ffa9cd570d3]
(on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(+0x4ca31)
[0x7ffa9cc30a31] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(+0x6cdc0)
[0x7ffa9cc50dc0] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: /usr/lib/x86_64-linux-
gnu/libevent-2.0.so.5(event_base_loop+0x7fc) [0x7ffa9c2673dc] (on Tor
0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(do_main_loop+0x25c)
[0x7ffa9cc34c9c] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(tor_run_main+0x265)
[0x7ffa9cc360b5] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(tor_main+0x3a)
[0x7ffa9cc2f71a] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(main+0x19)
[0x7ffa9cc2f489] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: /lib/x86_64-linux-
gnu/libc.so.6(__libc_start_main+0xf1) [0x7ffa9b45a2b1] (on Tor 0.3.3.0
-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(_start+0x2a)
[0x7ffa9cc2f4da] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] tor_bug_occurred_(): Bug:
src/or/hs_service.c:2245: upload_descriptor_to_hsdir: Non-fatal assertion
!(hs_desc_encode_descriptor(desc->desc, &desc->signing_kp, &encoded_desc)
< 0) failed. (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: Non-fatal assertion
!(hs_desc_encode_descriptor(desc->desc, &desc->signing_kp, &encoded_desc)
< 0) failed in upload_descriptor_to_hsdir at src/or/hs_service.c:2245.
Stack trace: (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(log_backtrace+0x42)
[0x7ffa9cd66ac2] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug:
./tor/src/or/tor(tor_bug_occurred_+0xb7) [0x7ffa9cd81cd7] (on Tor 0.3.3.0
-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug:
./tor/src/or/tor(hs_service_run_scheduled_events+0x23e7) [0x7ffa9cd572c7]
(on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(+0x4ca31)
[0x7ffa9cc30a31] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(+0x6cdc0)
[0x7ffa9cc50dc0] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: /usr/lib/x86_64-linux-
gnu/libevent-2.0.so.5(event_base_loop+0x7fc) [0x7ffa9c2673dc] (on Tor
0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(do_main_loop+0x25c)
[0x7ffa9cc34c9c] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(tor_run_main+0x265)
[0x7ffa9cc360b5] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(tor_main+0x3a)
[0x7ffa9cc2f71a] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(main+0x19)
[0x7ffa9cc2f489] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: /lib/x86_64-linux-
gnu/libc.so.6(__libc_start_main+0xf1) [0x7ffa9b45a2b1] (on Tor 0.3.3.0
-alpha-dev d69c8f7117a5975a)
Jan 21 08:03:04.000 [warn] Bug: ./tor/src/or/tor(_start+0x2a)
[0x7ffa9cc2f4da] (on Tor 0.3.3.0-alpha-dev d69c8f7117a5975a)
}}}
That started happening 4 days after I started up Tor and it persists up to
today: my HS is still unable to create its own desc...
FWIW, the only difference from the past is that I've been using vanguards
but that should not influence the signing of the desc....
--
--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/24972#comment:1>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online
More information about the tor-bugs
mailing list