ordb1 uses milliseconds in its descriptor, spec says it can't

router ordb1 213.246.53.127 8002 0 0
platform Tor 0.2.3.25 on Linux x86_64
opt protocols Link 1 2 Circuit 1
published 2013-07-17 13:38:46.992

But dir-spec.txt says

    "published" YYYY-MM-DD HH:MM:SS NL

       [Exactly once]

       The time, in UTC, when this descriptor (and its corresponding
       extra-info document if any)  was generated.

It looks like it's violating the spec. Should we (i.e. the directory authorities) have validated and refused the descriptor?

Is it our Tor implementation that does this on a weird edge case, or did somebody mess with something?

(Noticed because contrib/exitlist can't handle it.)

changed milestone to %Tor: 0.2.6.x-final

added 026-triaged-1 component::core tor/tor milestone::Tor: 0.2.6.x-final nickm-patch priority::high resolution::fixed status::closed tor-client type::defect labels

It can't be our implementation; ours writes into an ISO_TIME_LEN buffer, and only takes a time_t as input.

I think that if I'd considered this case, my intent would be to validate and reject. Whether we should do so now is up to you.

I think we should reject then. It's triggered a traceback in the exitlist script; and who knows what other parsing tools, now and in the future, will get upset by it.

(Turns out ordb1 isn't Running, so it hasn't made it into the consensus.)

Issue. Our parse_iso_time function currently accepts and ignores any junk after the seconds. So if we change it to reject stuff, we'll be making the behavior of a whole lot of Tor instances different than it was before. There are 27 instances of parse_iso_time thoughout Tor. 15 of those are in src/or/routerparse.c.

Time to start auditing?

We should also audit every other sscanf to see if it accepts and ignores extra junk.

Okay. The biggest impact I can see here is that if we make this change, it will be easy to make a descriptor (or a hidden service descriptor!) that older Tors accept, but newer Tors don't. Other parse_iso_time users are parsing tor-generated local files.

Related bugs (ignoring extra junk in the sscanf) exist in handling RFC1123 time and HTTP time.

and who knows what other parsing tools, now and in the future, will get upset by it.

For stems part the descriptor parser validation will fail with...

>>> datetime.datetime.strptime("published 2013-07-17 13:38:46.992", "%Y-%m-%d %H:%M:%S")
ValueError: time data 'published 2013-07-17 13:38:46.992' does not match format '%Y-%m-%d %H:%M:%S'

If you disable descriptor validation then the published attribute will simply be unset.

Possibly a crazy thought but maybe some directory authorities should run stem's descriptor parser over the consensuses they publish? Stem's validation checks for pretty strict conformance to the spec, so it's likely catch issues tor itself doesn't (see the results from #7828 (closed)). I've also thought about writing a script to pull each consensus on my side and validate it - easy to do once I've finished with this remote descriptor fetching API.

Replying to nickm:

Okay. The biggest impact I can see here is that if we make this change, it will be easy to make a descriptor (or a hidden service descriptor!) that older Tors accept, but newer Tors don't. Other parse_iso_time users are parsing tor-generated local files.

One possibility for now: check these items strictly when we're acting as a directory authority or a hidden service directory, and leniently otherwise.

Replying to nickm:

One possibility for now: check these items strictly when we're acting as a directory authority or a hidden service directory, and leniently otherwise.

I'm a fan!

See branch 'bug9286' in my public repository. It is more or less completely untested, and needs a changes file and a bette rcommit message, but it's worth examining and trying out. It's against 0.2.4.

Trac:
Priority: normal to major
Keywords: N/A deleted, tor-client added
Status: new to needs_review

running it on moria1. so far it seems to do something akin to working.

that said, it gives me a pile of Jul 19 00:53:41.549 [warn] ISO time "2013-07-17 13:38:46.992" was unparseable lines with no hints about caused it to be unhappy (if we're going to warn here, then the caller should warn too, to explain what we just decided not to do).

Seg fault.

#0  0x000000000042181f in cell_queue_append (queue=0x6a96328, 
    cell=0x7fff6fa27070, wide_circ_ids=0, use_stats=0) at src/or/relay.c:2141
#1  cell_queue_append_packed_copy (queue=0x6a96328, cell=0x7fff6fa27070, 
    wide_circ_ids=0, use_stats=0) at src/or/relay.c:2181
#2  0x000000000048006d in circuitmux_append_destroy_cell (chan=0x6aa83b0, 
    cmux=0x6a96300, circ_id=59857, reason=<value optimized out>)
    at src/or/circuitmux.c:1874
#3  0x000000000046ae39 in channel_send_destroy (circ_id=59857, 
    chan=0x6aa83b0, reason=<value optimized out>) at src/or/channel.c:2687
#4  0x000000000047f3cc in circuit_mark_for_close_ (circ=0x9f78af0, reason=0, 
    line=1250, file=0x53fa9b "src/or/circuituse.c")
    at src/or/circuitlist.c:1568
#5  0x0000000000478de8 in circuit_send_next_onion_skin (circ=0x9f78af0)
    at src/or/circuitbuild.c:808
#6  0x000000000042595a in connection_edge_process_relay_cell (
    cell=0x7fff6fa27c30, circ=0x9f78af0, conn=<value optimized out>, 
    layer_hint=<value optimized out>) at src/or/relay.c:1443
#7  0x00000000004264a0 in circuit_receive_relay_cell (cell=0x7fff6fa27c30, 
    circ=0x9f78af0, cell_direction=CELL_DIRECTION_IN) at src/or/relay.c:226
#8  0x000000000048d9de in command_process_relay_cell (chan=0x6aa83b0, 
    cell=0x7fff6fa27c30) at src/or/command.c:462
#9  command_process_cell (chan=0x6aa83b0, cell=0x7fff6fa27c30)
    at src/or/command.c:148
#10 0x00000000004724cb in channel_tls_handle_cell (cell=0x7fff6fa27c30, 
    conn=0x6aa7b00) at src/or/channeltls.c:924
#11 0x00000000004af286 in connection_or_process_cells_from_inbuf (
    conn=0x6aa7b00) at src/or/connection_or.c:1972
#12 0x00000000004a4038 in connection_handle_read_impl (conn=0x6aa7b00)
    at src/or/connection.c:2949
#13 connection_handle_read (conn=0x6aa7b00) at src/or/connection.c:2990
#14 0x000000000040c076 in conn_read_callback (fd=<value optimized out>, 
    event=29298, _conn=0x1) at src/or/main.c:716
#15 0x00007fe757dab344 in event_base_loop () from /usr/lib/libevent-1.4.so.2
#16 0x0000000000409e81 in do_main_loop () at src/or/main.c:1996
#17 0x000000000040a1dd in tor_main (argc=<value optimized out>, 
    argv=<value optimized out>) at src/or/main.c:2720
#18 0x00007fe75705cc8d in __libc_start_main (main=<value optimized out>, 
    argc=<value optimized out>, ubp_av=<value optimized out>, 
    init=<value optimized out>, fini=<value optimized out>, 
    rtld_fini=<value optimized out>, stack_end=0x7fff6fa28378)
    at libc-start.c:228
#19 0x0000000000408789 in _start ()

Looks like this might be a different bug?

This is git master (e1d3b444952d8) with your bug9286 merged into it.

#0  0x000000000042181f in cell_queue_append (queue=0x6a96328,
    cell=0x7fff6fa27070, wide_circ_ids=0, use_stats=0) at src/or/relay.c:2141
2141      TOR_SIMPLEQ_INSERT_TAIL(&queue->head, cell, next);
(gdb) print *queue
$5 = {head = {sqh_first = 0x15b015a00000158, sqh_last = 0x15f015e015d015c},
  n = 23134560, insertion_times = 0x1660240023f}

that's kind of a large queue->n, isn't it.

Ok, I reproduced this new bug on a vanilla git master, and filed #9296 (moved). Sorry for the pollution.

Replying to arma:

running it on moria1. so far it seems to do something akin to working.

that said, it gives me a pile of Jul 19 00:53:41.549 [warn] ISO time "2013-07-17 13:38:46.992" was unparseable lines with no hints about caused it to be unhappy (if we're going to warn here, then the caller should warn too, to explain what we just decided not to do).

Ok, this wasn't as cool as I'd been thinking: moria1 seems to be in a "oh hey dizum has a descriptor I don't have, let's fetch it" "oh that's not really a descriptor, let's drop it" loop.

Yuck. We could add a feature to break that loop, I guess? That look-breaking part sure doesn't feel like an 0.2.4 feature though.

Trac:
Status: needs_review to needs_revision

Moving nearly all needs_revision tickets into 0.2.6, as now untimely for 0.2.5.

Trac:
Milestone: Tor: 0.2.5.x-final to Tor: 0.2.6.x-final

Blocking on #11243 (moved)

Trac:
Keywords: tor-client deleted, tor-client 026-triaged-1 added

Add nickm-patch keyword to needs_revision tickets in 0.2.6 where (I think) I wrote the patch, so I know which ones are my responsibility to revise.

Trac:
Keywords: tor-client 026-triaged-1 deleted, tor-client, 026-triaged-1, nickm-patch added

I believe that now that I merged #11243 (moved), this is safe to merge?

Trac:
Status: needs_revision to needs_review

I've made an updated version as bug9286_v2; please review . (The changes are to rebase to master, fix conflicts, and add a changes file)

Now it's bug9286_v3_squashed, which is shorter. Now merging.

Trac:
Resolution: N/A to fixed
Status: needs_review to closed

closed

mentioned in issue #9296 (moved)

mentioned in issue #11243 (moved)

moved to tpo/core/tor#9286 (closed)

mentioned in issue tpo/core/tor#9296 (closed)

mentioned in issue tpo/core/tor#11243 (closed)