[metrics-bugs] #29787 [Metrics/Onionperf]: Enumerate possible failure cases and include failure information in .tpf output

[Tor Bug Tracker & Wiki]

#29787: Enumerate possible failure cases and include failure information in .tpf
output
-------------------------------+------------------------------
 Reporter:  karsten            |          Owner:  metrics-team
     Type:  enhancement        |         Status:  new
 Priority:  Medium             |      Milestone:
Component:  Metrics/Onionperf  |        Version:
 Severity:  Normal             |     Resolution:
 Keywords:                     |  Actual Points:
Parent ID:                     |         Points:
 Reviewer:                     |        Sponsor:
-------------------------------+------------------------------

Comment (by karsten):

 Please disregard my suggestion to drop the source port entirely. I hadn't
 thought of requests being started every 5 minutes and running for up to 60
 minutes. I still had the torperf model in mind where 50 KiB requests would
 be started every 5 minutes and killed 5 seconds before the next request.
 Same with 1 MiB/5 MiB requests with different timings. So, this suggestion
 didn't really make sense. Sorry for the possible confusion.

 In the spirit of release early release often, I'm sharing some early
 results here:

 {{{
 $ grep "_changeState" onionperf_2019-0*.tgen.log | sed 's/.*moving from
 state //' | sed 's/ to state />/' | tr '\n' ';' | sed
 's/CONNECT/_CONNECT/g' | tr '_' '\n' | sort | uniq -c | sort -nr
 18476
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>PAYLOAD;PAYLOAD>CHECKSUM;CHECKSUM>SUCCESS;
   81
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>ERROR;COMMAND>ERROR;
    5
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>PAYLOAD;
    4
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>PAYLOAD;SUCCESS>ERROR;PAYLOAD>ERROR;
    3
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;SUCCESS>ERROR;RESPONSE>ERROR;
    3
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>ERROR;
    2
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>PAYLOAD;PAYLOAD>CHECKSUM;CHECKSUM>SUCCESS;SUCCESS>ERROR;PAYLOAD>ERROR;
    2
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>PAYLOAD;PAYLOAD>CHECKSUM;CHECKSUM>SUCCESS;PAYLOAD>ERROR;
    1
 CONNECT>INIT;INIT>CHOICE;CHOICE>REQUEST;REQUEST>RESPONSEA;RESPONSEA>RESPONSEB;RESPONSEB>RESPONSEC;RESPONSEC>SUCCESS;COMMAND>RESPONSE;RESPONSE>PAYLOAD;PAYLOAD>CHECKSUM;CHECKSUM>SUCCESS;PAYLOAD>CHECKSUM;CHECKSUM>SUCCESS;
    1
 }}}

 Explanation: These are the state changes for >18k OnionPerf runs performed
 by op-ab since mid-January. Each measurement starts with CONNECT, followed
 by a state change to INIT, then CHOICE, and so on. The first line contains
 the successful runs, whereas most of the following lines contain errors.

 I need to take a break now, but after the break I'll look more at those
 lines except for the first to see what happens. I hope to find out why
 these measurements broke. Maybe I'll have to look at tor controller event
 logs or tor logs. Still, looking at 101 cases sounds manually sounds like
 it could work. We'll see!

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/29787#comment:5>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online