From 00fd5b67bf3310e86f32c1380129e17e045d29d3 Mon Sep 17 00:00:00 2001 From: Joey Hess Date: Thu, 13 Aug 2015 16:15:22 -0400 Subject: [PATCH] more measuring --- ..._3161719c0e2a72cdc44d7c7263c44ed9._comment | 35 +++++++++++++++++++ 1 file changed, 35 insertions(+) create mode 100644 doc/todo/speed_up_transfers_over_ssh+rsync_--_directly_reuse_the_same_connection__63__/comment_7_3161719c0e2a72cdc44d7c7263c44ed9._comment diff --git a/doc/todo/speed_up_transfers_over_ssh+rsync_--_directly_reuse_the_same_connection__63__/comment_7_3161719c0e2a72cdc44d7c7263c44ed9._comment b/doc/todo/speed_up_transfers_over_ssh+rsync_--_directly_reuse_the_same_connection__63__/comment_7_3161719c0e2a72cdc44d7c7263c44ed9._comment new file mode 100644 index 0000000000..09082f3368 --- /dev/null +++ b/doc/todo/speed_up_transfers_over_ssh+rsync_--_directly_reuse_the_same_connection__63__/comment_7_3161719c0e2a72cdc44d7c7263c44ed9._comment @@ -0,0 +1,35 @@ +[[!comment format=mdwn + username="joey" + subject="""comment 7""" + date="2015-08-13T18:27:35Z" + content=""" +I've made --debug be passed along to git-annex-shell, so here's a more +detailed view: + + [2015-08-13 15:29:05.183231] read: rsync ["--progress","--inplace","--perms","-e","'ssh' '-S' '.git/annex/ssh/localhost' '-o' 'ControlMaster=auto' '-o' 'ControlPersist=yes' '-T' 'localhost' 'git-annex-shell ''sendkey'' ''/home/joey/tmp/r'' ''--debug'' ''SHA256E-s30--6b1bd2aa19d658de59c3a5a1eb239cefb87bdfa0f9b64d1a670d88c211972c0d'' --uuid ba2a51f9-f356-40a7-9600-2ac4193c7d58 ''--'' ''remoteuuid=72078ee3-1150-45f0-b00e-53e971921982'' ''direct='' ''associatedfile=ook2'' ''--'''","--","dummy:",".git/annex/tmp/SHA256E-s30--6b1bd2aa19d658de59c3a5a1eb239cefb87bdfa0f9b64d1a670d88c211972c0d"] + [2015-08-13 15:29:05.219572] transfer start + [2015-08-13 15:29:05.221625] call: rsync ["--server","-t","--inplace","-e.Lsf",".","--sender","tmp/r/.git/annex/objects/wX/k9/SHA256E-s30--6b1bd2aa19d658de59c3a5a1eb239cefb87bdfa0f9b64d1a670d88c211972c0d/SHA256E-s30--6b1bd2aa19d658de59c3a5a1eb239cefb87bdfa0f9b64d1a670d88c211972c0d"] + [2015-08-13 15:29:05.226709] process done ExitSuccess # rsync server + [2015-08-13 15:29:05.22709] transfer done + [2015-08-13 15:29:05.247464] process done ExitSuccess # rsync client + +1. 0.036341s -- starting local rsync, ssh connection (using mux), and git-annex-shell startup to the point it parses parameters and can start + printing debug messages +2. 0.002053s -- time git-annex-shell spends starting transfer (locking file, etc) +3. 0.005084s -- actual file transfer time (including rsync server startup) +4. 0.000381s -- git-annex-shell shutdown time +5. 0.020374s -- time from when git-annex-shell exits until the local rsync exits. + This must consist of rsync writing the file, the ssh connection shutdown, and rsync shutdown. + I don't know in what porportions, except that writing the file is only a very small part of it. + +So, over 25000 files, I'd estimate the newly optimised git-annex to take +around 28 minutes here (unoptimized would have taken 171 minutes). +The rough time breakdown is: + +* 15 minutes is needed to start the rsync clients, ssh connections, git-annex-shell processes +* 9 minutes more overhead seems to be involved in shutting down those + connections +* 1 minute is used by git-annex-shell to do locking, etc +* 2 minutes is used by git-annex to find files to transfer, update location logs, etc +* 1 minute is used by rsync server to start running and send the files (assuming very small files and fast network) +"""]]