<div dir="ltr"><div>Hey Karsten & Dev team,<br><br></div><div>I didn't mean to take this off channel, so my apologies for that.<br></div><div><br>I ran a few more tests this week (and my apologies on the slowness of some of this work - life has been hectic this past month), but I am not finding much of use. I could not find any errors which are not also present in when N23 is disabled. If you want to browse the logs for yourself, I uploaded a partial log from a run to <a href="http://www.charliebelmer.com/scallion.n23.log">http://www.charliebelmer.com/scallion.n23.log</a> (730MB).<br>
<br></div>The most telling entries I found so far are below, but I see the same errors whether UseN23 is set to 1 or not, so it is likely not the root cause. I'll keep digging.<br><br>Error 1 (Seems to occur when opening channel):<br>
0:0:49:406270 [thread-2] 0:9:41:348157618 [scallion-info] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] bw_weights_error_t networkstatus_check_weights(int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int)(): Bw weight mismatch 1. G=214 M=12174 E=165 D=27654 T=40207 Wmd=4769 Wme=-724848 Wmg=0 Wed=461 Wee=734848 Wgd=4769 Wgg=10000 Wme=-724848 Wmg=0<br>
0:0:49:407692 [thread-2] 0:9:41:348157618 [scallion-info] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] bw_weights_error_t networkstatus_check_weights(int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int64_t, int)(): Bw weight mismatch 1. G=214 M=12174 E=165 D=27654 T=40207 Wmd=4769 Wme=-724848 Wmg=0 Wed=461 Wee=734848 Wgd=4769 Wgg=10000 Wme=-724848 Wmg=0<br>
<br>Error 2:<br>0:0:54:227263 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void conn_read_callback(int, short, void *)(): socket 1000264 wants to read.<br>0:0:54:227281 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] int connection_read_to_buf(connection_t *, ssize_t *, int *)(): 1000264: starting, inbuf_datalen 0 (0 pending in tls object). at_most 16448.<br>
0:0:54:227302 [thread-2] 0:10:55:012000001 [shadow-debug] [4uthority1-73.1.0.0] [_tcp_endOfFileSignalled] <a href="http://73.1.0.0:10021">73.1.0.0:10021</a> (descriptor 1000264) <-> <a href="http://91.1.0.0:9111">91.1.0.0:9111</a>: signaling close to user, socket no longer usable<br>
0:0:54:227321 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] TLS error: unexpected close while reading (SSL negotiation finished successfully)<br>0:0:54:227338 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] int tor_tls_read(tor_tls_t *, char *, size_t)(): read returned r=0, err=-8<br>
0:0:54:227354 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] int connection_read_to_buf(connection_t *, ssize_t *, int *)(): TLS connection closed on read. Closing. (Nickname nonexit10, address 91.1.0.0)<br>
0:0:54:227373 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void channel_close_for_error(channel_t *)(): Closing channel 0x7f546d03ce40 due to lower-layer error<br>0:0:54:227389 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void channel_change_state(channel_t *, channel_state_t)(): Changing state of channel 0x7f546d03ce40 (global ID 21) from "open" to "closing"<br>
0:0:54:227420 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void channel_remove_from_digest_map(channel_t *)(): Removed channel 0x7f546d03ce40 (global ID 21) from identity map in state closing (4) with digest BBF25A366EA5376B0026CE6EDE3DF536211429BE<br>
0:0:54:227440 [thread-2] 0:10:55:012000001 [shadow-debug] [4uthority1-73.1.0.0] [tcp_close] <a href="http://73.1.0.0:10021">73.1.0.0:10021</a> (descriptor 1000264) <-> <a href="http://91.1.0.0:9111">91.1.0.0:9111</a>:  user closed connection<br>
0:0:54:227452 [thread-2] 0:10:55:012000001 [shadow-debug] [4uthority1-73.1.0.0] [_tcp_setState] <a href="http://73.1.0.0:10021">73.1.0.0:10021</a> (descriptor 1000264) <-> <a href="http://91.1.0.0:9111">91.1.0.0:9111</a>: moved from TCP state 'TCPS_CLOSEWAIT' to 'TCPS_LASTACK'<br>
0:0:54:227473 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void connection_mark_for_close_internal_(connection_t *, int, const char *)(): Calling connection_mark_for_close_internal_() on an OR conn at /home/coffee/shadow/shadow/build/tor/src/or/connection.c:2932<br>
0:0:54:227491 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] int conn_close_if_marked(int)(): Cleaning up connection (fd -1).<br>0:0:54:227509 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void circuit_n_chan_done(channel_t *, int)(): chan to NULL/<a href="http://91.1.0.0:9111">91.1.0.0:9111</a>, status=0<br>
0:0:54:227546 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] void channel_change_state(channel_t *, channel_state_t)(): Changing state of channel 0x7f546d03ce40 (global ID 21) from "closing" to "channel error"<br>
0:0:54:227565 [thread-2] 0:10:55:012000001 [scallion-debug] [4uthority1-73.1.0.0] [scalliontor_logmsg_cb] int connection_remove(connection_t *)(): removing socket -1 (type OR), n_conns now 26<br><br><br></div><div class="gmail_extra">
<br><br><div class="gmail_quote">On Tue, Sep 3, 2013 at 10:47 AM, Karsten Loesing <span dir="ltr"><<a href="mailto:karsten@torproject.org" target="_blank">karsten@torproject.org</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div class="im">On 9/3/13 4:32 PM, Charlie Belmer wrote:<br>
> Hi Karsten,<br>
><br>
> I have run several tests, but I haven't been able to satisfy myself yet. I<br>
> attached the results from my latest round of tests for your review. I am<br>
> comparing the n23 branch (UseN23 1 set in each torrc) with the initial head<br>
> I merged n23 with. It seems that for some reason, the n23 branch completes<br>
> far fewer downloads, though I haven't yet found the cause, or found<br>
> anything interesting in the logs.<br>
><br>
> $ grep "fg-download-complete" m1.large-tor/data/scallion.log | wc -l<br>
> 8827<br>
> $ grep "fg-download-complete" m1.large-n23/scallion.log | wc -l<br>
> 308<br>
><br>
> I would definitely appreciate any thoughts, insights, or advice!<br>
<br>
</div>Interesting!  Can you re-run the n23 simulation on info or even debug<br>
log level?  That might reveal some more information.  You'll do that by<br>
running "scallion --log-level=INFO".  A tiny network should be<br>
sufficient for that.  Watch out for filling disks.<br>
<br>
If you want me to look at the scallion.log file, feel free to post it<br>
somewhere, and I'll see if something looks unusual to me.<br>
<br>
Thanks,<br>
Karsten<br>
<div class="HOEnZb"><div class="h5"><br>
<br>
> On Tue, Sep 3, 2013 at 8:58 AM, Karsten Loesing <<a href="mailto:karsten@torproject.org">karsten@torproject.org</a>>wrote:<br>
><br>
>> Hi Charlie,<br>
>><br>
>> did you have the chance to simulate your rebased n23-5 branch using Shadow?<br>
>><br>
>> If not, maybe I can help by simulating it once and writing down more<br>
>> specific instructions for you?<br>
>><br>
>> Thanks!<br>
>> Karsten<br>
>><br>
>><br>
>> On 8/8/13 10:36 AM, Karsten Loesing wrote:<br>
>>> (Moving this discussion back to tor-dev@ with Charlie's permission.)<br>
>>><br>
>>> On 8/6/13 4:10 AM, Charlie Belmer wrote:<br>
>>>> Hey Karsten,<br>
>>>><br>
>>>> I've been reading up on Shadow & Scallion to do some performance<br>
>> testing on<br>
>>>> N23. Before I go too far down that road, I wanted to check in with you.<br>
>>>><br>
>>>> Are there existing blueprints or best practices I should be following?<br>
>>><br>
>>> Thanks for looking into this!<br>
>>><br>
>>> So, I wouldn't call the following notes blueprints or best practices,<br>
>>> but they are a description of what I would do to run Shadow simulations<br>
>>> of your branch.<br>
>>><br>
>>> First of all, be sure to read the Shadow wiki which has contains lots of<br>
>>> interesting stuff: <a href="https://github.com/shadow/shadow/wiki" target="_blank">https://github.com/shadow/shadow/wiki</a><br>
>>><br>
>>> The next step would be to get a vanilla Tor master (that your branch is<br>
>>> based on) running in a minimal or tiny Shadow network.  It's probably<br>
>>> easiest to use a local Ubuntu VM for this.  Or you can start an m1.large<br>
>>> EC2 instance for the tiny network, or an even smaller instance for the<br>
>>> minimal network.<br>
>>><br>
>>> Once that simulation succeeds, you'll want to run another simulation<br>
>>> using your branch, extract performance metrics using Shadow's analyze<br>
>>> script, produce a PDF with graphs also using the analyze script, and<br>
>>> then wonder if things are faster than before.<br>
>>><br>
>>> The minimal or tiny networks are mostly there to learn that things are<br>
>>> working as expected.  You'll probably want larger networks for real<br>
>>> performance results, but starting small to get everything working is<br>
>>> probably easier.<br>
>>><br>
>>> Sounds doable, I guess.  However, here's where things start to get<br>
>>> tricky: in order to simulate Tor master (or a branch based on it) in<br>
>>> Shadow, you'll have to perform quite a few extra steps like compiling<br>
>>> your own CMake and Clang/LLVM.  Not really hard, but you need to get all<br>
>>> pieces together before Shadow does what you want.<br>
>>><br>
>>> I'm pasting detailed instructions that I used to simulate Steven's uTP<br>
>>> branch in Shadow below as an example.  Not everything applies to your<br>
>>> branch, but it should give you the general idea.<br>
>>><br>
>>> If something remains unclear, please feel free to ask!<br>
>>><br>
>>>> Depending how it goes, I'd also look at re-trying adaptive 23 or tuning<br>
>> the<br>
>>>> existing implementation.<br>
>>><br>
>>> Neat!  We should probably include Mashael in that discussion once you<br>
>>> have a working and simulated n23-5 branch.  Maybe she has ideas what<br>
>>> parts need tweaking.  I'm cc'ing her in this mail so she knows what<br>
>>> you're working on.<br>
>>><br>
>>> In any case, having a working rebased n23-5 branch is already a big step<br>
>>> forward.<br>
>>><br>
>>> Thanks!<br>
>>> Karsten<br>
>>><br>
>>><br>
>>> === START OF INSTRUCTIONS ===<br>
>>><br>
>>> Launch new EC2 instance running Ubuntu Server 13.04 64 bit<br>
>>><br>
>>> Set ulimit -n to 25000, see Shadow wiki for details<br>
>>><br>
>> <a href="https://github.com/shadow/shadow/wiki/Preparing-your-machine#system-configs-and-limits" target="_blank">https://github.com/shadow/shadow/wiki/Preparing-your-machine#system-configs-and-limits</a><br>
>>><br>
>>> $ sudo apt-get update<br>
>>> $ sudo apt-get upgrade<br>
>>><br>
>>> Clone and test-compile modified libutp<br>
>>><br>
>>> $ sudo apt-get install build-essential git automake libssl-dev<br>
>> libevent-dev<br>
>>> $ mkdir src<br>
>>> $ cd src/<br>
>>> $ git clone <a href="https://github.com/sjmurdoch/libutp" target="_blank">https://github.com/sjmurdoch/libutp</a><br>
>>> $ cd libutp/<br>
>>> $ make<br>
>>> $ cd ../<br>
>>><br>
>>> Clone and test-compile Tor branch utp<br>
>>><br>
>>> $ git clone <a href="https://git.torproject.org/tor.git" target="_blank">https://git.torproject.org/tor.git</a><br>
>>> $ cd tor/<br>
>>> $ git remote add sjm217 <a href="https://git.torproject.org/sjm217/tor.git" target="_blank">https://git.torproject.org/sjm217/tor.git</a><br>
>>> $ git fetch sjm217<br>
>>> $ git checkout -b utp sjm217/utp<br>
>>> $ ./autogen.sh<br>
>>> $ LDFLAGS="-L/home/ubuntu/src/libutp" CFLAGS="-I/home/ubuntu/src/libutp"<br>
>>> LIBS="-lutp -lrt" ./configure --disable-asciidoc<br>
>>> $ make<br>
>>> $ make distclean<br>
>>> $ cd ../<br>
>>><br>
>>> Modify Tor to use uTP for all links (or "0 &&" for not using uTP for any<br>
>>> link)<br>
>>><br>
>>> diff --git a/src/or/channeltls.c b/src/or/channeltls.c<br>
>>> index 0551b73..b7b36e1 100644<br>
>>> --- a/src/or/channeltls.c<br>
>>> +++ b/src/or/channeltls.c<br>
>>> @@ -418,7 +418,7 @@ channel_tls_connect(const tor_addr_t *addr, uint16_t<br>
>>> port,<br>
>>>    /* Create a uTP connection */<br>
>>>    tor_addr_to_sockaddr(addr, port, (struct sockaddr*)&sin, sizeof(sin));<br>
>>>    tor_addr_to_str(addr_str, addr, sizeof(addr_str), 0);<br>
>>> -  if (!strncmp(addr_str, "128.232.10.129", sizeof(addr_str))) {<br>
>>> +  if (1 || !strncmp(addr_str, "128.232.10.129", sizeof(addr_str))) {<br>
>>>      log_info(LD_CHANNEL,<br>
>>>               "Trying uTP connection to %s", addr_str);<br>
>>>      tlschan->utp = UTP_Create(tor_UTPSendToProc, tlschan, (const struct<br>
>>> sockaddr*)&sin,<br>
>>><br>
>>> Install CMake 2.8.10<br>
>>><br>
>>> $ wget <a href="http://www.cmake.org/files/v2.8/cmake-2.8.10.2.tar.gz" target="_blank">http://www.cmake.org/files/v2.8/cmake-2.8.10.2.tar.gz</a><br>
>>> $ tar xf cmake-2.8.10.2.tar.gz<br>
>>> $ cd cmake-2.8.10.2/<br>
>>> $ ./configure<br>
>>> $ make<br>
>>> $ export PATH=~/src/cmake-2.8.10.2/bin:$PATH<br>
>>> $ cd ../<br>
>>> $ which cmake # result: /home/ubuntu/src/cmake-2.8.10.2/bin/cmake<br>
>>><br>
>>> Build Clang and LLVM from source<br>
>>><br>
>>> $ wget <a href="http://llvm.org/releases/3.2/llvm-3.2.src.tar.gz" target="_blank">http://llvm.org/releases/3.2/llvm-3.2.src.tar.gz</a><br>
>>> $ wget <a href="http://llvm.org/releases/3.2/clang-3.2.src.tar.gz" target="_blank">http://llvm.org/releases/3.2/clang-3.2.src.tar.gz</a><br>
>>> $ tar xaf llvm-3.2.src.tar.gz<br>
>>> $ tar xaf clang-3.2.src.tar.gz<br>
>>> $ cp -R clang-3.2.src llvm-3.2.src/tools/clang<br>
>>> $ cd llvm-3.2.src/<br>
>>> $ mkdir build<br>
>>> $ cd build/<br>
>>> $ cmake -DCMAKE_INSTALL_PREFIX=/home/ubuntu/.local ../.<br>
>>> $ make<br>
>>> $ make install<br>
>>> $ export PATH=~/.local/bin/:$PATH<br>
>>> $ cd ../../<br>
>>> $ which clang # result: /home/ubuntu/.local/bin//clang<br>
>>><br>
>>> Install Shadow<br>
>>><br>
>>> $ sudo apt-get install gcc xz-utils make automake autoconf cmake tidy<br>
>>> libtidy-dev libglib2.0 libglib2.0-dev dstat pdftk python2.7<br>
>>> python-matplotlib python-numpy python-scipy<br>
>>> $ git clone <a href="https://github.com/shadow/shadow.git" target="_blank">https://github.com/shadow/shadow.git</a><br>
>>> $ cd shadow<br>
>>> $ ./setup dependencies<br>
>>> $ ./setup build -g -i /home/ubuntu/src/libutp -i<br>
>>> /usr/include/x86_64-linux-gnu/c++/4.7 -l /home/ubuntu/src/libutp<br>
>>> --tor-prefix /home/ubuntu/src/tor --tor-lib utp<br>
>>> $ ./setup install<br>
>>> $ export PATH=~/.shadow/bin/:$PATH<br>
>>><br>
>>> Simulate tiny network in Shadow<br>
>>><br>
>>> $ cd resource/examples/scallion/<br>
>>> $ tar xf tiny-4GB-m1.large.tar.xz<br>
>>> $ cd tiny-4GB-m1.large/<br>
>>> $ scallion<br>
>>><br>
>>> Graph simulation results<br>
>>><br>
>>> Add one line to beginning of analyze.py:<br>
>>><br>
>>> import matplotlib; matplotlib.use('Agg')<br>
>>><br>
>>> For additional traffic simulations:<br>
>>><br>
>>> $ grep -v "\[traffic-" scallion.log > scallion-notraffic.log<br>
>>><br>
>>> $ cd ~/src/<br>
>>> $ mkdir results<br>
>>> $ cd results/<br>
>>> $ python ~/src/shadow/contrib/analyze.py parse --output uTP-1<br>
>>><br>
>> ~/src/shadow/resource/examples/scallion/tiny-4GB-m1.large/data-utp-1/scallion.log<br>
>>> $ python ~/src/shadow/contrib/analyze.py parse --output uTP-0<br>
>>><br>
>> ~/src/shadow/resource/examples/scallion/tiny-4GB-m1.large/data-utp-0/scallion.log<br>
>>> $ python ~/src/shadow/contrib/analyze.py parse --output vanilla<br>
>>><br>
>> ~/src/shadow/resource/examples/scallion/tiny-4GB-m1.large/data-vanilla/scallion.log<br>
>>> $ python ~/src/shadow/contrib/analyze.py plot --title "sjm217's utp<br>
>>> branch (#9166)" --prefix "sjm217-utp" --data vanilla/ "vanilla<br>
>>> 0.2.4.4-alpha" --data uTP-1/ "uTP for all links" --data uTP-0/ "uTP for<br>
>>> none of the links"<br>
>>><br>
>>> === END OF INSTRUCTIONS ===<br>
>>><br>
>>><br>
>><br>
>><br>
><br>
<br>
</div></div></blockquote></div><br></div>