[tahoe-dev] clarification on time stats for Immutable files and mutable files ?

[Brian Warner]

On 2/9/11 12:20 AM, sreenivasulu velpula wrote:
> When an upload happens on Tahoe grid for an immutable file, It will
> give time statistics, i didn't understand some of those timings.

> + Storage Index: 1.2ms (192.3kBps) 
>  /( I assume this is the time for hashing encryption
>     key and generating storage index)/

Right. The clock starts when the Uploader code first opens the file
(which is after an HTTP PUT/POST has finished receiving the data and
writing it to a tempfile). Then it reads the contents, hashes them into
an encryption key, hashes the encryption key into a storage index, then
stops the clock. The disk IO and SHA256 time dominate.

>  + Peer Selection: 81 seconds
>  /(I didn't understand what is peer selection, can any one explain it ?)/

That's the time it takes to ask each storage server if they'll hold a
share for us. We send requests to servers in a particular order (the
"permuted server list"), and wait for responses. If a server says "no"
(maybe because they don't have enough space left). We finish when enough
servers have said "yes" to let us place enough shares on sufficiently
diverse servers. We try to send multiple requests in parallel, but we
also don't want to send out too many requests (like if you had 500
storage servers but only wanted to place 10 shares), so sometimes the
requests are send serially.

81 seconds is huge for that. It really ought to take less than a second:
the messages are tiny. Either your network connection is busy doing
something else (so the requests or their responses get stuck behind
other data), or several servers are responding very very slowly.

> + Encode And Push: 37 seconds (7.6kBps)
> 
> /(I assume this is the time to take splitting the file into segments,
> erasure coding of segments and then send erasure coded blocks to
> servers)/

Yes. We work on one segment at a time. For each segment, we read the
plaintext, encrypt it, erasure-code the ciphertext, hash it, then push
the ciphertext blocks to the storage servers. We wait for all servers to
accept one segment before starting on the next (to keep our memory
footprint low). After the last segment, we send a bunch of
integrity-checking hashes, and then a "close()" message to commit the
share to disk.

This clock starts when we get the "yes" response from the last storage
server that we want to use, and finishes when we get back the response
from the last close().

> # Cumulative Encoding: 7.4ms (31.6kBps)
> /(I didn't understand what is Cumulative Encoding, can any one explain
> it ?)/

This is the portion of "Encode And Push" spent doing erasure coding.
It's the sum of time spent in the one zfec.encode() call per segment. We
include it to prove to people that encoding is generally really fast and
so they shouldn't be afraid about its overhead. (your system took 7.4ms
to encode a 285 byte file, which shows that the process has a couple of
ms of constant constant. If the file were larger, the rate would look
better, usually tens of megabytes per second).

> # Cumulative Pushing: 24ms (10.0kBps)
> /(I didn't understand what is Cumulative Pushing, can any one explain
> it ?)/

This is the portion of "Encode And Push" spent sending shares to storage
servers: purely network and server-turnaround time. For each segment,
the clock starts when we start sending a share to the first server, and
ends when we get the acknowledgment back from the last server. These
times are then summed over all segments.

> # Send Hashes And Close: 36 seconds
> /(Is it the time required to send Merkle hash trees to storage
> servers)/

Right. That clock starts when we start sending hashes and close()
messages to the first server, and stops when we get the ack from the
close() message form the last server.

> -> But when we upload file as Mutable, time stats are not getting
> displayed, Is there any way to generate these time stats on Mutable
> file also ?

Unfortunately I didn't write as much timing-gathering code for the
Mutable publish process. I think there's a little bit on the Recent
Uploads And Downloads page, but not nearly as much as for immutable
files. Partly it's because the process is very different, and partly
it's because we've been designing around *small* mutable files until
fairly recently, so we haven't been as concerned about things like how
long it takes to encrypt/hash/encode them.

> -> Are there any utilities available from Tahoe to know, how much time
> it will take to generate key,  time required to generate cipher text
> with the key, time required to do erasure coding and  time required to
> send erasure coded blocks to storage servers ?

For immutable files, the key is generated during the "Storage Index"
phase. We don't currently have a measure of how long encryption takes (I
think we used to, but some internal architecture change made it go
away).. that'd be a good thing to add back in (it should go into
src/allmydata/immutable/upload.py in
EncryptAnUploadable._hash_and_encrypt_plaintext, and should accumulate
elapsed time around the call to self._encryptor.process .. patches
welcome!). Erasure coding is the "Cumulative Encoding" time. And sending
erasure coded blocks is the "Cumulative Pushing" time.

hope that helps!
 -Brian