Add/multiprocessing #634

vsoch · 2017-04-24T07:27:23Z

This is the first PR to add multiprocessing to downloads, which, with some trivial testing, seems like it might speed things up by a small amount (see here http://www.vanessasaur.us/rawr/2017/multiprocess/). A few things I'd like to talk about:

Progress Bar

the stream downloader now has the progress bar removed, in favor of including it with the multiprocessing calls (to ensure that you don't see crazy output). This also means that the updates are less frequent, and a lot more jumpy (eg, one bar is shown for all layers, and it proceeds when a layer is done. I used Pool.imap instead of Pool.imap_unordered or Pool.apply_async to ensure that the ordering is preserved. This also means that the progress bar is gone for shub, and this should be changed. I'd like to have a discussion about a new progress bar strategy - is there a more ideal visual that can be shown that doesn't have the arrow > making the user expecting more moving progress? If so, should we do the same for the shub image, or implement the old version for that (having the call to bot.show_progress be in separate functions, which is different than how it was before, both were in the stream function.

Testing

I'd like to have some test this out on different OS and CPUs to see if it does make a difference. And also get feedback on tweaking the MultiProcess module that I added in case we can make it faster.

I noticed strange behavior with pool, that it would print an empty newline after each process. As a fix I wrote a mute function that sends stderr output to null, and that resolved it. I don't think I need to close this, but wanted to check.

Going to sleep!

@singularityware-admin

vsoch · 2017-04-24T18:10:26Z

As yes and two more things that came to mind now that I've slept a bit:

the number of workers is a variable. It will depend on the running environment. This means we might expose it via an environment or config variable (likely config since the user could specify something suboptimal for the cluster) or have a calculation that figures it out automatically. The suggestions I saw were 2*CPU, but in testing on my small instance I found that generally odd numbers were better, eg 3,5,7.
Logging. I also figured out how to get the workers sending their logging to the log, and this can be done at the same level as the Singularity logger.

vsoch · 2017-04-24T20:06:03Z

ok I'm running on a n1-standard-32 (32 vCPUs, 120 GB memory) machine. First with a dinky image, ubuntu:latest. Here are results:

serial

[30.841593980789185,
 30.764344930648804,
 30.08139419555664,
 29.94521188735962,
 29.80375099182129,
 30.066102981567383,
 30.142144918441772,
 29.913299083709717,
 30.201260805130005,
 30.04903221130371]

Here are times using 2* CPU, in this case, 64 workers

[28.287593126296997,
 27.664984941482544,
 27.844917058944702,
 28.089011192321777,
 28.063278198242188,
 27.838926076889038,
 28.12764596939087,
 28.15303897857666,
 28.949312925338745,
 28.98016881942749]

(not remarkably different)

and finally here are times that are varying the workers (the idea being one configuration would be most optimal)

{1: 31.716920137405396,
 2: 27.720598936080933,
 3: 28.177881956100464,
 4: 27.763348817825317,
 5: 27.959540128707886,
 6: 27.824767112731934,
 7: 27.991510152816772,
 8: 27.83053994178772,
 9: 28.043720960617065,
 10: 27.929732084274292,
 11: 28.3353009223938,
 12: 28.204150915145874,
 13: 28.106995105743408,
 14: 28.08035182952881,
 15: 28.072475910186768,
 16: 28.16374707221985,
 17: 30.745393991470337,
 18: 28.644512176513672,
 19: 28.469332933425903,
 20: 28.34295082092285,
 21: 28.574687957763672,
 22: 28.814728021621704,
 23: 28.784103870391846,
 24: 28.82189178466797,
 25: 29.055819988250732,
 26: 28.978917837142944,
 27: 29.062932014465332,
 28: 29.211053133010864,
 29: 29.674387216567993}

Again, it's really not convincingly different to warrant adding this. What I'm doing next is testing a much heftier image (one with 24 layers that are each much larger) and from there, I would suggest the following:

if we see a difference, proceed with questions posted above
if we don't see a difference, discuss if there are other components of the python API that would benefit from the multiprocessing, and if so, try those out.
if no to both of the above, we can drop the PR.

For those interested in running their own test cases (@ArangoGutierrez) I have provided the testing code here. And you of course can use the PR here if you don't want to work internally in Python with simple dummy functions.

vsoch · 2017-04-24T23:02:47Z

ok a quick update on testing this (trivially) with a larger image. It's expensive so I limited to the test to a subset of layers [0:12] for poldracklab/mriqc. I also ran it just once, so we are going to miss any and all variance. The serial test is as follows:

# ('Serial download time:', 547.8233549594879)

and the multiprocessing hung and never finished, and I wasn't able to get any kind of log, but I can talk about my observations.

What I observed is that the multiprocessing handled the smaller layers simultaneously, and they were all completed very quickly. The bottle neck was the larger layers - because we are still handling the layer download and permission changes via one worker. This means that any improvements / speed ups in time are due to making the smaller layers efficient to finish in "parallel" but the bottle neck is always going to be the largest layer. Interestingly enough, dumping more stuff into one layer is the recommended Dockery way of doing things, to prevent having more smaller layers. It's even farther from our approach since we are working with entire image files.

It would be great if someone that has this kind of infrastructure could test this proper, or just give me a log in and I'll do it. I can't be charging my group dollars per hour for it, it's not really good.

vsoch · 2017-04-25T12:51:38Z

In case it's of interest (even outside this PR) there are modules in python that let us do a pretty detailed logging of every function call! For example, here is just creating the client and getting images for ubuntu:latest:

         1456 function calls (1393 primitive calls) in 2.560 seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        4    0.956    0.239    1.320    0.330 socket.py:537(create_connection)
        4    0.780    0.195    0.780    0.195 ssl.py:401(do_handshake)
        4    0.455    0.114    0.455    0.114 ssl.py:254(read)
       12    0.365    0.030    0.365    0.030 socket.py:223(meth)
        4    0.001    0.000    0.781    0.195 ssl.py:202(__init__)
       19    0.000    0.000    0.000    0.000 message.py:146(write)
       40    0.000    0.000    0.455    0.011 socket.py:406(readline)
     12/4    0.000    0.000    0.000    0.000 sre_parse.py:379(_parse)
    32/14    0.000    0.000    0.000    0.000 sre_parse.py:140(getwidth)
        8    0.000    0.000    0.000    0.000 ssl.py:394(close)
        9    0.000    0.000    0.000    0.000 urllib2.py:323(add_handler)
        4    0.000    0.000    0.000    0.000 httplib.py:267(readheaders)
        4    0.000    0.000    0.000    0.000 socket.py:192(close)
        4    0.000    0.000    0.000    0.000 ssl.py:290(send)
       24    0.000    0.000    0.000    0.000 httplib.py:980(putheader)
        4    0.000    0.000    2.557    0.639 urllib2.py:1139(do_open)
        8    0.000    0.000    0.000    0.000 socket.py:185(__init__)
     22/4    0.000    0.000    0.000    0.000 sre_compile.py:32(_compile)
      3/2    0.000    0.000    2.558    1.279 base.py:159(submit_request)
        4    0.000    0.000    0.781    0.195 ssl.py:476(wrap_socket)
      3/2    0.000    0.000    2.559    1.280 base.py:130(get)
        4    0.000    0.000    0.455    0.114 httplib.py:437(begin)
        6    0.000    0.000    0.000    0.000 urlparse.py:168(urlsplit)
        3    0.000    0.000    0.000    0.000 utf_8.py:15(decode)
       19    0.000    0.000    0.000    0.000 message.py:112(emit)
        4    0.000    0.000    0.455    0.114 httplib.py:398(_read_status)
    12/10    0.000    0.000    0.000    0.000 socket.py:276(close)
        4    0.000    0.000    2.101    0.525 httplib.py:822(send)
      8/3    0.000    0.000    0.000    0.000 socket.py:336(read)
        2    0.000    0.000    0.000    0.000 decoder.py:372(raw_decode)
      103    0.000    0.000    0.000    0.000 sre_parse.py:182(__next)
        4    0.000    0.000    2.101    0.525 httplib.py:1212(connect)
        4    0.000    0.000    0.455    0.114 httplib.py:1053(getresponse)
        4    0.000    0.000    2.102    0.525 httplib.py:1036(_send_request)
        4    0.000    0.000    2.557    0.639 urllib2.py:386(open)
        6    0.000    0.000    0.000    0.000 urlparse.py:137(urlparse)
        3    0.000    0.000    0.000    0.000 sre_compile.py:207(_optimize_charset)
      2/1    0.000    0.000    1.876    1.876 api.py:113(update_token)
        1    0.000    0.000    0.000    0.000 urllib.py:1361(getproxies_environment)
        8    0.000    0.000    0.000    0.000 socket.py:246(__init__)
        4    0.000    0.000    0.001    0.000 re.py:226(_compile)
        4    0.000    0.000    0.000    0.000 mimetools.py:24(__init__)
       76    0.000    0.000    0.000    0.000 sre_parse.py:130(__getitem__)
        4    0.000    0.000    0.000    0.000 urllib2.py:199(__init__)
        4    0.000    0.000    0.000    0.000 mimetools.py:33(parsetype)
        4    0.000    0.000    0.000    0.000 urllib.py:1067(splittype)
        4    0.000    0.000    0.000    0.000 urllib2.py:181(request_host)
        1    0.000    0.000    0.000    0.000 urllib2.py:454(build_opener)
        4    0.000    0.000    0.000    0.000 urllib2.py:1110(do_request_)
        4    0.000    0.000    0.000    0.000 urllib.py:1172(splittag)
        4    0.000    0.000    0.001    0.000 sre_compile.py:493(compile)
        2    0.000    0.000    0.000    0.000 decoder.py:361(decode)
     12/4    0.000    0.000    0.000    0.000 sre_parse.py:301(_parse_sub)
        4    0.000    0.000    0.000    0.000 sre_compile.py:478(_code)
        4    0.000    0.000    0.000    0.000 sre_parse.py:675(parse)
        2    0.000    0.000    0.000    0.000 httplib.py:614(_read_chunked)
       10    0.000    0.000    0.000    0.000 <string>:8(__new__)
        4    0.000    0.000    0.000    0.000 ssl.py:463(makefile)
        4    0.000    0.000    2.101    0.525 httplib.py:849(_send_output)
        4    0.000    0.000    0.000    0.000 httplib.py:370(__init__)
        4    0.000    0.000    0.000    0.000 sre_compile.py:359(_compile_info)
       62    0.000    0.000    0.000    0.000 sre_parse.py:138(append)
       26    0.000    0.000    0.000    0.000 httplib.py:253(addheader)
       19    0.000    0.000    0.000    0.000 message.py:80(emitError)
       10    0.000    0.000    2.557    0.256 urllib2.py:374(_call_chain)
        5    0.000    0.000    0.000    0.000 urllib.py:952(__init__)
        4    0.000    0.000    0.000    0.000 urllib.py:1081(splithost)
        4    0.000    0.000    2.557    0.639 urllib2.py:414(_open)
        4    0.000    0.000    0.000    0.000 ssl.py:320(sendall)
       26    0.000    0.000    0.000    0.000 rfc822.py:197(isheader)
        4    0.000    0.000    0.000    0.000 rfc822.py:88(__init__)
        1    0.000    0.000    0.000    0.000 api.py:333(read_digests)
        4    0.000    0.000    2.557    0.639 urllib2.py:1221(https_open)
        2    0.000    0.000    0.000    0.000 base.py:46(update_headers)
        1    0.000    0.000    0.684    0.684 api.py:208(get_manifest)
      8/7    0.000    0.000    0.000    0.000 socket.py:285(__del__)
       10    0.000    0.000    0.000    0.000 sre_compile.py:354(_simple)
        3    0.000    0.000    0.000    0.000 urlparse.py:160(_splitnetloc)
        1    0.000    0.000    0.000    0.000 shell.py:71(parse_image_uri)
        5    0.000    0.000    0.000    0.000 urllib.py:1006(__init__)
        4    0.000    0.000    0.000    0.000 httplib.py:870(putrequest)
        1    0.000    0.000    1.876    1.876 api.py:68(__init__)
        7    0.000    0.000    0.000    0.000 httplib.py:553(close)
        4    0.000    0.000    0.000    0.000 base.py:189(prepare_request)
        4    0.000    0.000    0.455    0.114 ssl.py:335(recv)
       88    0.000    0.000    0.000    0.000 sre_parse.py:201(get)
       54    0.000    0.000    0.000    0.000 sre_parse.py:195(match)
        8    0.000    0.000    0.000    0.000 urllib2.py:261(get_host)
        4    0.000    0.000    2.558    0.639 urllib2.py:123(urlopen)
        4    0.000    0.000    0.000    0.000 mimetools.py:50(parseplist)
        2    0.000    0.000    0.000    0.000 sutils.py:59(add_http)
       12    0.000    0.000    0.000    0.000 message.py:234(debug)
        4    0.000    0.000    0.000    0.000 urllib2.py:516(http_response)
        2    0.000    0.000    0.000    0.000 UserDict.py:40(items)
        1    0.000    0.000    1.876    1.876 api.py:179(get_tags)
        8    0.000    0.000    0.000    0.000 urllib2.py:254(get_type)
        6    0.000    0.000    0.000    0.000 httplib.py:569(read)
        4    0.000    0.000    2.102    0.525 httplib.py:1015(request)
        4    0.000    0.000    0.000    0.000 httplib.py:726(__init__)
        4    0.000    0.000    0.000    0.000 httplib.py:812(close)
       28    0.000    0.000    0.000    0.000 httplib.py:842(_output)
       24    0.000    0.000    0.000    0.000 urllib2.py:1168(<genexpr>)
       22    0.000    0.000    0.000    0.000 sre_parse.py:90(__init__)
       19    0.000    0.000    0.000    0.000 message.py:104(isEnabledFor)
        4    0.000    0.000    0.000    0.000 httplib.py:1204(__init__)
        3    0.000    0.000    0.000    0.000 sre_compile.py:178(_compile_charset)
        1    0.000    0.000    0.000    0.000 re.py:134(match)
        1    0.000    0.000    0.000    0.000 urllib2.py:429(error)
        1    0.000    0.000    0.000    0.000 urllib2.py:154(__init__)
       30    0.000    0.000    0.000    0.000 rfc822.py:209(islast)
        8    0.000    0.000    0.000    0.000 urllib2.py:289(add_header)
        4    0.000    0.000    0.000    0.000 httplib.py:756(_set_hostport)
        4    0.000    0.000    0.000    0.000 httplib.py:523(_check_close)
        4    0.000    0.000    0.000    0.000 urllib.py:1058(unwrap)
        4    0.000    0.000    0.000    0.000 httplib.py:672(_safe_read)
        1    0.000    0.000    2.560    2.560 test_stuff.py:9(main)
       13    0.000    0.000    0.000    0.000 urllib2.py:503(__lt__)
        4    0.000    0.000    2.101    0.525 httplib.py:1000(endheaders)
       30    0.000    0.000    0.000    0.000 rfc822.py:219(iscomment)
        8    0.000    0.000    0.000    0.000 sre_parse.py:83(closegroup)
        4    0.000    0.000    0.000    0.000 urllib.py:1210(unquote)
        2    0.000    0.000    0.000    0.000 __init__.py:293(loads)
        1    0.000    0.000    0.684    0.684 api.py:157(get_images)
       24    0.000    0.000    0.000    0.000 rfc822.py:285(getheader)
        8    0.000    0.000    0.000    0.000 sre_compile.py:472(isstring)
        8    0.000    0.000    0.000    0.000 sre_parse.py:72(opengroup)
        1    0.000    0.000    1.876    1.876 api.py:100(load_image)
       40    0.000    0.000    0.000    0.000 sre_parse.py:126(__len__)
       12    0.000    0.000    0.000    0.000 urllib2.py:1157(<genexpr>)
       10    0.000    0.000    0.000    0.000 urllib2.py:248(get_full_url)
        8    0.000    0.000    0.000    0.000 socket.py:292(flush)
        8    0.000    0.000    0.000    0.000 urllib2.py:293(add_unredirected_header)
        7    0.000    0.000    0.000    0.000 message.py:222(verbose)
        4    0.000    0.000    0.000    0.000 sre_parse.py:178(__init__)
        4    0.000    0.000    0.000    0.000 urllib.py:1043(_is_unicode)
       10    0.000    0.000    0.000    0.000 sre_parse.py:134(__setitem__)
        8    0.000    0.000    0.000    0.000 urllib2.py:242(has_data)
        8    0.000    0.000    0.000    0.000 urllib2.py:496(add_parent)
        6    0.000    0.000    0.000    0.000 urlparse.py:206(<genexpr>)
        4    0.000    0.000    0.000    0.000 httplib.py:776(set_debuglevel)
        4    0.000    0.000    0.000    0.000 urllib2.py:231(get_method)
        3    0.000    0.000    0.000    0.000 re.py:188(compile)
        1    0.000    0.000    0.000    0.000 base.py:32(__init__)
        1    0.000    0.000    0.000    0.000 urllib2.py:714(__init__)
        8    0.000    0.000    0.000    0.000 urllib2.py:297(has_header)
        4    0.000    0.000    0.000    0.000 sre_parse.py:67(__init__)
        4    0.000    0.000    0.000    0.000 urllib2.py:268(get_selector)
        2    0.000    0.000    0.000    0.000 urllib2.py:1104(__init__)
        1    0.000    0.000    0.000    0.000 rfc822.py:439(__contains__)
        1    0.000    0.000    0.000    0.000 urllib2.py:530(http_error_default)
        1    0.000    0.000    0.000    0.000 rfc822.py:386(__getitem__)
        1    0.000    0.000    0.000    0.000 UserDict.py:70(__contains__)
        1    0.000    0.000    0.000    0.000 sre_parse.py:257(_escape)
        1    0.000    0.000    0.000    0.000 urllib2.py:312(__init__)
        8    0.000    0.000    0.000    0.000 sre_compile.py:24(_identityfunction)
        4    0.000    0.000    0.000    0.000 urllib2.py:280(has_proxy)
        4    0.000    0.000    0.000    0.000 urllib.py:1012(info)
        1    0.000    0.000    0.000    0.000 api.py:94(_init_headers)
        0    0.000             0.000          profile:0(profiler)

it's a bit of a hack, but the script to run the test (sitting in libexec/python) is like:

#!/usr/bin/env python

import os
import sys
sys.path.append(os.path.join(os.path.dirname(__file__),'docker'))
print(sys.path)
from api import DockerApiConnection

def main():
    client = DockerApiConnection(image='ubuntu:latest')
    images = client.get_images()
    

if __name__ == '__main__':
  main()

and then the profiler is like

import hotshot, hotshot.stats
import sys
import os
sys.path.append(os.getcwd())

def main():
  module = __import__(sys.argv[1].replace('.py', ''))
  prof = hotshot.Profile('example.prof')
  prof.runcall(module.main)
  prof.close()

  stats = hotshot.stats.load('example.prof')
  stats.strip_dirs()
  stats.sort_stats('time', 'calls')
  stats.print_stats()

if __name__ == '__main__':
  main()

then I'm calling just like:

 python ../../../profiler.py test_stuff.py

it could of course be done a lot more cleanly, targeted toward some use, just wanted to share in case it's desired.

vsoch · 2017-04-25T12:53:05Z

https://docs.python.org/2/library/hotshot.html

ArangoGutierrez · 2017-04-25T21:02:37Z

Here are some results using the "hack" script and the PR installed on my host ( Dual XEON DeLL WS)

Average Download speed using speedtest-cli : 53.94 Mbit/s

['/tmp/singularity/libexec/python', '/usr/lib/python27.zip', '/usr/lib64/python2.7', '/usr/lib64/python2.7/plat-linux2', '/usr/lib64/python2.7/lib-tk', '/usr/lib64/python2.7/lib-old', '/usr/lib64/python2.7/lib-dynload', '/usr/lib64/python2.7/site-packages', '/usr/lib64/python2.7/site-packages/gtk-2.0', '/usr/lib/python2.7/site-packages', '/tmp/singularity/libexec/python', '/tmp/singularity/libexec/python/docker']
VERBOSE2 SINGULARITY_COMMAND_ASIS found as False
VERBOSE2 SINGULARITY_ROOTFS not defined (None)
VERBOSE2 SINGULARITY_METADATA_FOLDER found as None/.singularity.d
VERBOSE2 SINGULARITY_DISABLE_CACHE found as False
VERBOSE2 SINGULARITY_CACHEDIR found as /home/Eduardo/.singularity
VERBOSE2 SINGULARITY_ENVBASE found as None/.singularity.d/env
VERBOSE2 SINGULARITY_LABELFILE found as None/.singularity.d/labels.json
VERBOSE2 SINGULARITY_INCLUDECMD found as False
VERBOSE2 SINGULARITY_PULLFOLDER found as /tmp/singularity/libexec/python
VERBOSE2 SHUB_NAMEBYHASH not defined (None)
VERBOSE2 SHUB_NAMEBYCOMMIT not defined (None)
VERBOSE2 SHUB_CONTAINERNAME not defined (None)
VERBOSE2 SINGULARITY_CONTENTS found as None/.singularity.d/.layers
DEBUG Headers found: Content-Type,Accept
VERBOSE Registry: index.docker.io
VERBOSE Namespace: library
VERBOSE Repo Name: ubuntu
VERBOSE Repo Tag: latest
VERBOSE Version: None
VERBOSE Obtaining tags: https://index.docker.io/v2/library/ubuntu/tags/list
DEBUG GET https://index.docker.io/v2/library/ubuntu/tags/list
DEBUG Http Error with code 401
DEBUG GET https://auth.docker.io/token?service=registry.docker.io&expires_in=9000&scope=repository:library/ubuntu:pull
DEBUG Headers found: Content-Type,Authorization,Accept
VERBOSE Obtaining manifest: https://index.docker.io/v2/library/ubuntu/manifests/latest
DEBUG GET https://index.docker.io/v2/library/ubuntu/manifests/latest
DEBUG Image manifest version 2.2 found.
DEBUG Adding digest sha256:aafe6b5e13de557451e1781fe7276620275625f970015cbd10036ab7d8ae27c0
DEBUG Adding digest sha256:0a2b43a726608d3835aa027bbe181624789130c212eb191baa481f1d788a0676
DEBUG Adding digest sha256:18bdd1e546d21240bd4c3e4e29032a38f18102d780a78686508d40fe01c60158
DEBUG Adding digest sha256:8198342c3e05101bb56b0a585dc34e39346ece39ee5d39287cda24b1fb445fed
DEBUG Adding digest sha256:f56970a44fd409805e3872cac236d29f5eed1a45e189bb765bcd2163c915f384
         1633 function calls (1568 primitive calls) in 2.436 seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        4    0.716    0.179    0.718    0.179 ssl.py:833(do_handshake)
        4    0.716    0.179    0.716    0.179 ssl.py:642(read)
        4    0.587    0.147    0.936    0.234 socket.py:541(create_connection)
       24    0.349    0.015    0.349    0.015 socket.py:227(meth)
        4    0.048    0.012    0.048    0.012 ssl.py:401(load_default_certs)
    12/10    0.007    0.001    0.007    0.001 socket.py:280(close)
        4    0.002    0.000    0.002    0.000 ssl.py:346(__new__)
       40    0.001    0.000    0.717    0.018 socket.py:410(readline)
      8/3    0.001    0.000    0.007    0.002 socket.py:340(read)
       19    0.001    0.000    0.001    0.000 message.py:146(write)
        4    0.000    0.000    0.000    0.000 ssl.py:673(getpeercert)
     13/5    0.000    0.000    0.001    0.000 sre_parse.py:395(_parse)
        4    0.000    0.000    0.718    0.180 ssl.py:529(__init__)
        8    0.000    0.000    0.000    0.000 ssl.py:814(close)
        4    0.000    0.000    0.001    0.000 httplib.py:271(readheaders)
        4    0.000    0.000    2.423    0.606 urllib2.py:1154(do_open)
        9    0.000    0.000    0.000    0.000 urllib2.py:348(add_handler)
       24    0.000    0.000    0.000    0.000 httplib.py:1005(putheader)
     24/5    0.000    0.000    0.000    0.000 sre_compile.py:64(_compile)
        8    0.000    0.000    0.000    0.000 socket.py:189(__init__)
        4    0.000    0.000    0.000    0.000 ssl.py:711(send)
        4    0.000    0.000    0.000    0.000 socket.py:196(close)
    35/16    0.000    0.000    0.000    0.000 sre_parse.py:151(getwidth)
      123    0.000    0.000    0.000    0.000 sre_parse.py:193(__next)
       19    0.000    0.000    0.001    0.000 message.py:112(emit)
        4    0.000    0.000    0.001    0.000 ssl.py:198(_dnsname_match)
        4    0.000    0.000    0.716    0.179 httplib.py:392(_read_status)
        4    0.000    0.000    0.717    0.179 httplib.py:431(begin)
        8    0.000    0.000    0.002    0.000 re.py:230(_compile)
        4    0.000    0.000    0.050    0.012 ssl.py:410(create_default_context)
        2    0.000    0.000    0.000    0.000 decoder.py:370(raw_decode)
        6    0.000    0.000    0.000    0.000 urlparse.py:168(urlsplit)
        8    0.000    0.000    0.000    0.000 re.py:208(escape)
        4    0.000    0.000    1.655    0.414 httplib.py:1067(_send_request)
      3/2    0.000    0.000    2.435    1.218 base.py:176(get)
       82    0.000    0.000    0.000    0.000 sre_parse.py:141(__getitem__)
        4    0.000    0.000    0.717    0.179 httplib.py:1084(getresponse)
      2/1    0.000    0.000    2.000    2.000 api.py:113(update_token)
        4    0.000    0.000    2.424    0.606 urllib2.py:411(open)
        4    0.000    0.000    0.718    0.180 ssl.py:355(wrap_socket)
        5    0.000    0.000    0.002    0.000 sre_compile.py:567(compile)
        2    0.000    0.000    0.005    0.002 httplib.py:609(_read_chunked)
        3    0.000    0.000    0.000    0.000 utf_8.py:15(decode)
       75    0.000    0.000    0.000    0.000 sre_parse.py:149(append)
      106    0.000    0.000    0.000    0.000 sre_parse.py:212(get)
        4    0.000    0.000    0.001    0.000 mimetools.py:24(__init__)
        4    0.000    0.000    0.001    0.000 urllib2.py:226(__init__)
        5    0.000    0.000    0.001    0.000 sre_parse.py:706(parse)
        4    0.000    0.000    1.654    0.414 httplib.py:1252(connect)
       24    0.000    0.000    0.000    0.000 urllib2.py:1184(<genexpr>)
        8    0.000    0.000    0.000    0.000 socket.py:250(__init__)
       26    0.000    0.000    0.000    0.000 rfc822.py:202(isheader)
        4    0.000    0.000    0.000    0.000 mimetools.py:33(parsetype)
     13/5    0.000    0.000    0.001    0.000 sre_parse.py:317(_parse_sub)
        4    0.000    0.000    0.000    0.000 urllib2.py:1125(do_request_)
        4    0.000    0.000    1.655    0.414 httplib.py:840(send)
        5    0.000    0.000    0.000    0.000 urllib.py:958(__init__)
        1    0.000    0.000    0.000    0.000 api.py:333(read_digests)
        4    0.000    0.000    0.000    0.000 urllib.py:1092(splithost)
        4    0.000    0.000    0.000    0.000 urllib.py:1078(splittype)
        4    0.000    0.000    2.423    0.606 urllib2.py:439(_open)
        4    0.000    0.000    0.000    0.000 urllib2.py:208(request_host)
        1    0.000    0.000    0.000    0.000 urllib.py:1372(getproxies_environment)
        6    0.000    0.000    0.000    0.000 urlparse.py:137(urlparse)
        4    0.000    0.000    0.000    0.000 urllib.py:1183(splittag)
        3    0.000    0.000    0.000    0.000 sre_compile.py:256(_optimize_charset)
        4    0.000    0.000    0.000    0.000 ssl.py:743(sendall)
        4    0.000    0.000    1.655    0.414 httplib.py:867(_send_output)
      8/7    0.000    0.000    0.002    0.000 socket.py:289(__del__)
        4    0.000    0.000    2.423    0.606 urllib2.py:1241(https_open)
        4    0.000    0.000    0.000    0.000 httplib.py:888(putrequest)
      3/2    0.000    0.000    2.428    1.214 base.py:205(submit_request)
        1    0.000    0.000    0.000    0.000 urllib2.py:479(build_opener)
       26    0.000    0.000    0.000    0.000 httplib.py:257(addheader)
        4    0.000    0.000    0.000    0.000 ssl.py:895(makefile)
        4    0.000    0.000    0.001    0.000 ssl.py:249(match_hostname)
        1    0.000    0.000    0.436    0.436 api.py:208(get_manifest)
        5    0.000    0.000    0.000    0.000 sre_compile.py:433(_compile_info)
        4    0.000    0.000    0.050    0.013 httplib.py:1239(__init__)
        1    0.000    0.000    0.000    0.000 shell.py:71(parse_image_uri)
        4    0.000    0.000    0.000    0.000 httplib.py:364(__init__)
       10    0.000    0.000    2.423    0.242 urllib2.py:399(_call_chain)
       19    0.000    0.000    0.000    0.000 message.py:80(emitError)
        2    0.000    0.000    0.000    0.000 decoder.py:359(decode)
        4    0.000    0.000    0.000    0.000 httplib.py:826(close)
        4    0.000    0.000    0.936    0.234 httplib.py:818(connect)
       24    0.000    0.000    0.000    0.000 rfc822.py:290(getheader)
        6    0.000    0.000    0.006    0.001 httplib.py:564(read)
        8    0.000    0.000    0.000    0.000 urllib2.py:286(get_host)
        4    0.000    0.000    0.000    0.000 httplib.py:721(__init__)
       11    0.000    0.000    0.000    0.000 sre_compile.py:428(_simple)
        5    0.000    0.000    0.000    0.000 urllib.py:1017(__init__)
        2    0.000    0.000    0.000    0.000 base.py:110(update_headers)
        7    0.000    0.000    0.001    0.000 re.py:192(compile)
        4    0.000    0.000    0.001    0.000 base.py:235(prepare_request)
        5    0.000    0.000    0.001    0.000 sre_compile.py:552(_code)
       10    0.000    0.000    0.000    0.000 <string>:8(__new__)
        4    0.000    0.000    0.001    0.000 rfc822.py:88(__init__)
        4    0.000    0.000    0.000    0.000 httplib.py:667(_safe_read)
       12    0.000    0.000    0.001    0.000 message.py:234(debug)
        4    0.000    0.000    0.000    0.000 mimetools.py:50(parseplist)
        4    0.000    0.000    0.716    0.179 ssl.py:759(recv)
       44    0.000    0.000    0.000    0.000 sre_parse.py:137(__len__)
        3    0.000    0.000    0.000    0.000 urlparse.py:160(_splitnetloc)
        1    0.000    0.000    2.000    2.000 api.py:179(get_tags)
       58    0.000    0.000    0.000    0.000 sre_parse.py:206(match)
        4    0.000    0.000    1.655    0.414 httplib.py:1040(request)
        1    0.000    0.000    0.001    0.001 re.py:138(match)
        4    0.000    0.000    2.424    0.606 urllib2.py:131(urlopen)
        4    0.000    0.000    0.000    0.000 urllib2.py:541(http_response)
        8    0.000    0.000    0.000    0.000 urllib2.py:279(get_type)
        7    0.000    0.000    0.007    0.001 httplib.py:547(close)
       30    0.000    0.000    0.000    0.000 rfc822.py:214(islast)
       24    0.000    0.000    0.000    0.000 sre_parse.py:92(__init__)
        5    0.000    0.000    0.000    0.000 sre_parse.py:268(_escape)
        2    0.000    0.000    0.000    0.000 sutils.py:59(add_http)
        1    0.000    0.000    0.000    0.000 urllib2.py:181(__init__)
        8    0.000    0.000    0.000    0.000 ssl.py:634(_check_connected)
        4    0.000    0.000    0.000    0.000 httplib.py:766(_get_hostport)
        3    0.000    0.000    0.000    0.000 sre_compile.py:228(_compile_charset)
        4    0.000    0.000    0.000    0.000 httplib.py:517(_check_close)
        4    0.000    0.000    0.000    0.000 urllib.py:1221(unquote)
        2    0.000    0.000    0.000    0.000 __init__.py:294(loads)
        1    0.000    0.000    0.000    0.000 urllib2.py:454(error)
       19    0.000    0.000    0.000    0.000 message.py:104(isEnabledFor)
       10    0.000    0.000    0.000    0.000 sre_compile.py:546(isstring)
        4    0.000    0.000    0.000    0.000 httplib.py:1044(_set_content_length)
        1    0.000    0.000    2.436    2.436 test_stuff.py:9(main)
        1    0.000    0.000    2.000    2.000 api.py:68(__init__)
        5    0.000    0.000    0.000    0.000 sre_parse.py:189(__init__)
       13    0.000    0.000    0.000    0.000 urllib2.py:528(__lt__)
       12    0.000    0.000    0.000    0.000 urllib2.py:1173(<genexpr>)
        8    0.000    0.000    0.000    0.000 urllib2.py:314(add_header)
        4    0.000    0.000    0.000    0.000 urllib.py:1069(unwrap)
        4    0.000    0.000    1.655    0.414 httplib.py:1025(endheaders)
        1    0.000    0.000    0.436    0.436 api.py:157(get_images)
       30    0.000    0.000    0.000    0.000 rfc822.py:224(iscomment)
       28    0.000    0.000    0.000    0.000 httplib.py:860(_output)
        7    0.000    0.000    0.000    0.000 message.py:222(verbose)
        1    0.000    0.000    0.000    0.000 urllib2.py:555(http_error_default)
       10    0.000    0.000    0.000    0.000 urllib2.py:273(get_full_url)
        8    0.000    0.000    0.000    0.000 urllib2.py:267(has_data)
        8    0.000    0.000    0.000    0.000 sre_parse.py:74(opengroup)
        8    0.000    0.000    0.000    0.000 sre_parse.py:85(closegroup)
        5    0.000    0.000    0.000    0.000 sre_parse.py:67(__init__)
        4    0.000    0.000    0.000    0.000 ssl.py:352(__init__)
        2    0.000    0.000    0.000    0.000 UserDict.py:57(items)
        1    0.000    0.000    2.000    2.000 api.py:100(load_image)
       20    0.000    0.000    0.000    0.000 ssl.py:630(_checkClosed)
        8    0.000    0.000    0.000    0.000 socket.py:296(flush)
        8    0.000    0.000    0.000    0.000 urllib2.py:322(has_header)
        8    0.000    0.000    0.000    0.000 urllib2.py:318(add_unredirected_header)
        4    0.000    0.000    0.000    0.000 urllib.py:1054(_is_unicode)
       11    0.000    0.000    0.000    0.000 sre_parse.py:145(__setitem__)
        4    0.000    0.000    0.000    0.000 httplib.py:785(set_debuglevel)
        4    0.000    0.000    0.000    0.000 urllib2.py:256(get_method)
        4    0.000    0.000    0.000    0.000 ssl.py:617(context)
        6    0.000    0.000    0.000    0.000 urlparse.py:206(<genexpr>)
        4    0.000    0.000    0.000    0.000 urllib2.py:293(get_selector)
        1    0.000    0.000    0.000    0.000 urllib2.py:337(__init__)
        1    0.000    0.000    0.000    0.000 urllib2.py:739(__init__)
        1    0.000    0.000    0.000    0.000 base.py:96(__init__)
        1    0.000    0.000    0.000    0.000 rfc822.py:444(__contains__)
        8    0.000    0.000    0.000    0.000 urllib2.py:521(add_parent)
        4    0.000    0.000    0.000    0.000 urllib2.py:305(has_proxy)
        1    0.000    0.000    0.000    0.000 urllib2.py:1237(__init__)
        4    0.000    0.000    0.000    0.000 urllib.py:1023(info)
        2    0.000    0.000    0.000    0.000 urllib2.py:1119(__init__)
        1    0.000    0.000    0.000    0.000 rfc822.py:391(__getitem__)
        1    0.000    0.000    0.000    0.000 api.py:94(_init_headers)
        1    0.000    0.000    0.000    0.000 UserDict.py:103(__contains__)
        0    0.000             0.000          profile:0(profiler)

['/tmp/singularity/libexec/python', '/usr/lib/python27.zip', '/usr/lib64/python2.7', '/usr/lib64/python2.7/plat-linux2', '/usr/lib64/python2.7/lib-tk', '/usr/lib64/python2.7/lib-old', '/usr/lib64/python2.7/lib-dynload', '/usr/lib64/python2.7/site-packages', '/usr/lib64/python2.7/site-packages/gtk-2.0', '/usr/lib/python2.7/site-packages', '/tmp/singularity/libexec/python', '/tmp/singularity/libexec/python/docker']
VERBOSE2 SINGULARITY_COMMAND_ASIS found as False
VERBOSE2 SINGULARITY_ROOTFS not defined (None)
VERBOSE2 SINGULARITY_METADATA_FOLDER found as None/.singularity.d
VERBOSE2 SINGULARITY_DISABLE_CACHE found as False
VERBOSE2 SINGULARITY_CACHEDIR found as /home/Eduardo/.singularity
VERBOSE2 SINGULARITY_ENVBASE found as None/.singularity.d/env
VERBOSE2 SINGULARITY_LABELFILE found as None/.singularity.d/labels.json
VERBOSE2 SINGULARITY_INCLUDECMD found as False
VERBOSE2 SINGULARITY_PULLFOLDER found as /tmp/singularity/libexec/python
VERBOSE2 SHUB_NAMEBYHASH not defined (None)
VERBOSE2 SHUB_NAMEBYCOMMIT not defined (None)
VERBOSE2 SHUB_CONTAINERNAME not defined (None)
VERBOSE2 SINGULARITY_CONTENTS found as None/.singularity.d/.layers
DEBUG Headers found: Content-Type,Accept
VERBOSE Registry: index.docker.io
VERBOSE Namespace: library
VERBOSE Repo Name: ubuntu
VERBOSE Repo Tag: latest
VERBOSE Version: None
VERBOSE Obtaining tags: https://index.docker.io/v2/library/ubuntu/tags/list
DEBUG GET https://index.docker.io/v2/library/ubuntu/tags/list
DEBUG Http Error with code 401
DEBUG GET https://auth.docker.io/token?service=registry.docker.io&expires_in=9000&scope=repository:library/ubuntu:pull
DEBUG Headers found: Content-Type,Authorization,Accept
VERBOSE Obtaining manifest: https://index.docker.io/v2/library/ubuntu/manifests/latest
DEBUG GET https://index.docker.io/v2/library/ubuntu/manifests/latest
DEBUG Image manifest version 2.2 found.
DEBUG Adding digest sha256:aafe6b5e13de557451e1781fe7276620275625f970015cbd10036ab7d8ae27c0
DEBUG Adding digest sha256:0a2b43a726608d3835aa027bbe181624789130c212eb191baa481f1d788a0676
DEBUG Adding digest sha256:18bdd1e546d21240bd4c3e4e29032a38f18102d780a78686508d40fe01c60158
DEBUG Adding digest sha256:8198342c3e05101bb56b0a585dc34e39346ece39ee5d39287cda24b1fb445fed
DEBUG Adding digest sha256:f56970a44fd409805e3872cac236d29f5eed1a45e189bb765bcd2163c915f384
         1633 function calls (1568 primitive calls) in 2.948 seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        4    1.331    0.333    1.693    0.423 socket.py:541(create_connection)
        4    0.713    0.178    0.714    0.179 ssl.py:833(do_handshake)
        4    0.481    0.120    0.481    0.120 ssl.py:642(read)
       24    0.362    0.015    0.362    0.015 socket.py:227(meth)
        4    0.043    0.011    0.043    0.011 ssl.py:401(load_default_certs)
    12/10    0.007    0.001    0.008    0.001 socket.py:280(close)
        4    0.001    0.000    0.001    0.000 ssl.py:346(__new__)
       40    0.001    0.000    0.482    0.012 socket.py:410(readline)
       19    0.001    0.000    0.001    0.000 message.py:146(write)
        8    0.001    0.000    0.001    0.000 socket.py:189(__init__)
      8/3    0.001    0.000    0.007    0.002 socket.py:340(read)
        4    0.000    0.000    0.000    0.000 ssl.py:673(getpeercert)
     13/5    0.000    0.000    0.001    0.000 sre_parse.py:395(_parse)
        8    0.000    0.000    0.001    0.000 ssl.py:814(close)
        4    0.000    0.000    0.715    0.179 ssl.py:529(__init__)
        4    0.000    0.000    2.935    0.734 urllib2.py:1154(do_open)
        9    0.000    0.000    0.000    0.000 urllib2.py:348(add_handler)
        4    0.000    0.000    0.001    0.000 httplib.py:271(readheaders)
     24/5    0.000    0.000    0.000    0.000 sre_compile.py:64(_compile)
       24    0.000    0.000    0.000    0.000 httplib.py:1005(putheader)
        4    0.000    0.000    0.001    0.000 ssl.py:198(_dnsname_match)
        4    0.000    0.000    0.000    0.000 ssl.py:711(send)
        4    0.000    0.000    0.000    0.000 socket.py:196(close)
    35/16    0.000    0.000    0.000    0.000 sre_parse.py:151(getwidth)
       19    0.000    0.000    0.001    0.000 message.py:112(emit)
      123    0.000    0.000    0.000    0.000 sre_parse.py:193(__next)
        8    0.000    0.000    0.002    0.000 re.py:230(_compile)
        4    0.000    0.000    0.482    0.120 httplib.py:431(begin)
        4    0.000    0.000    0.044    0.011 ssl.py:410(create_default_context)
        8    0.000    0.000    0.000    0.000 re.py:208(escape)
        2    0.000    0.000    0.000    0.000 decoder.py:370(raw_decode)
        6    0.000    0.000    0.000    0.000 urlparse.py:168(urlsplit)
        4    0.000    0.000    2.409    0.602 httplib.py:1067(_send_request)
      3/2    0.000    0.000    2.947    1.474 base.py:176(get)
        4    0.000    0.000    0.481    0.120 httplib.py:392(_read_status)
        4    0.000    0.000    0.482    0.120 httplib.py:1084(getresponse)
       82    0.000    0.000    0.000    0.000 sre_parse.py:141(__getitem__)
        4    0.000    0.000    2.936    0.734 urllib2.py:411(open)
      2/1    0.000    0.000    2.576    2.576 api.py:113(update_token)
        4    0.000    0.000    0.715    0.179 ssl.py:355(wrap_socket)
        5    0.000    0.000    0.002    0.000 sre_compile.py:567(compile)
        2    0.000    0.000    0.005    0.003 httplib.py:609(_read_chunked)
        4    0.000    0.000    0.001    0.000 mimetools.py:24(__init__)
      106    0.000    0.000    0.000    0.000 sre_parse.py:212(get)
        4    0.000    0.000    0.001    0.000 urllib2.py:226(__init__)
        4    0.000    0.000    2.408    0.602 httplib.py:1252(connect)
        5    0.000    0.000    0.001    0.000 sre_parse.py:706(parse)
        8    0.000    0.000    0.000    0.000 socket.py:250(__init__)
        4    0.000    0.000    2.408    0.602 httplib.py:840(send)
        1    0.000    0.000    0.001    0.001 api.py:333(read_digests)
        3    0.000    0.000    0.000    0.000 utf_8.py:15(decode)
        4    0.000    0.000    0.000    0.000 urllib2.py:1125(do_request_)
        4    0.000    0.000    0.000    0.000 ssl.py:743(sendall)
        4    0.000    0.000    0.000    0.000 mimetools.py:33(parsetype)
       24    0.000    0.000    0.000    0.000 urllib2.py:1184(<genexpr>)
        1    0.000    0.000    0.000    0.000 urllib2.py:479(build_opener)
       26    0.000    0.000    0.000    0.000 rfc822.py:202(isheader)
        5    0.000    0.000    0.000    0.000 urllib.py:958(__init__)
        4    0.000    0.000    1.693    0.423 httplib.py:818(connect)
        6    0.000    0.000    0.000    0.000 urlparse.py:137(urlparse)
        4    0.000    0.000    0.000    0.000 urllib.py:1078(splittype)
        4    0.000    0.000    0.000    0.000 urllib2.py:208(request_host)
        1    0.000    0.000    0.000    0.000 urllib.py:1372(getproxies_environment)
      8/7    0.000    0.000    0.002    0.000 socket.py:289(__del__)
        5    0.000    0.000    0.000    0.000 sre_compile.py:433(_compile_info)
        4    0.000    0.000    2.935    0.734 urllib2.py:439(_open)
        4    0.000    0.000    0.000    0.000 urllib.py:1183(splittag)
        4    0.000    0.000    2.408    0.602 httplib.py:867(_send_output)
        3    0.000    0.000    0.000    0.000 sre_compile.py:256(_optimize_charset)
     13/5    0.000    0.000    0.001    0.000 sre_parse.py:317(_parse_sub)
        4    0.000    0.000    0.000    0.000 httplib.py:888(putrequest)
        4    0.000    0.000    0.001    0.000 ssl.py:249(match_hostname)
       26    0.000    0.000    0.000    0.000 httplib.py:257(addheader)
        4    0.000    0.000    2.935    0.734 urllib2.py:1241(https_open)
       10    0.000    0.000    2.935    0.294 urllib2.py:399(_call_chain)
        1    0.000    0.000    0.371    0.371 api.py:208(get_manifest)
      3/2    0.000    0.000    2.940    1.470 base.py:205(submit_request)
       19    0.000    0.000    0.000    0.000 message.py:80(emitError)
        4    0.000    0.000    0.000    0.000 ssl.py:895(makefile)
        4    0.000    0.000    0.044    0.011 httplib.py:1239(__init__)
        4    0.000    0.000    0.000    0.000 urllib.py:1092(splithost)
        4    0.000    0.000    0.000    0.000 httplib.py:364(__init__)
        6    0.000    0.000    0.007    0.001 httplib.py:564(read)
       58    0.000    0.000    0.000    0.000 sre_parse.py:206(match)
        2    0.000    0.000    0.000    0.000 decoder.py:359(decode)
       75    0.000    0.000    0.000    0.000 sre_parse.py:149(append)
       24    0.000    0.000    0.000    0.000 rfc822.py:290(getheader)
        4    0.000    0.000    0.000    0.000 httplib.py:721(__init__)
        2    0.000    0.000    0.000    0.000 base.py:110(update_headers)
        4    0.000    0.000    0.001    0.000 rfc822.py:88(__init__)
       11    0.000    0.000    0.000    0.000 sre_compile.py:428(_simple)
        5    0.000    0.000    0.000    0.000 sre_parse.py:189(__init__)
        1    0.000    0.000    0.000    0.000 urllib2.py:454(error)
        7    0.000    0.000    0.001    0.000 re.py:192(compile)
       10    0.000    0.000    0.000    0.000 <string>:8(__new__)
       12    0.000    0.000    0.001    0.000 message.py:234(debug)
        8    0.000    0.000    0.000    0.000 urllib2.py:286(get_host)
        4    0.000    0.000    2.936    0.734 urllib2.py:131(urlopen)
        4    0.000    0.000    0.481    0.120 ssl.py:759(recv)
        1    0.000    0.000    2.576    2.576 api.py:179(get_tags)
        5    0.000    0.000    0.000    0.000 urllib.py:1017(__init__)
        4    0.000    0.000    0.001    0.000 base.py:235(prepare_request)
        3    0.000    0.000    0.000    0.000 urlparse.py:160(_splitnetloc)
        4    0.000    0.000    0.000    0.000 httplib.py:667(_safe_read)
       24    0.000    0.000    0.000    0.000 sre_parse.py:92(__init__)
        5    0.000    0.000    0.001    0.000 sre_compile.py:552(_code)
        4    0.000    0.000    0.000    0.000 mimetools.py:50(parseplist)
        1    0.000    0.000    0.000    0.000 shell.py:71(parse_image_uri)
        8    0.000    0.000    0.000    0.000 urllib2.py:279(get_type)
        4    0.000    0.000    0.000    0.000 urllib2.py:541(http_response)
        7    0.000    0.000    0.008    0.001 httplib.py:547(close)
        4    0.000    0.000    2.409    0.602 httplib.py:1040(request)
        1    0.000    0.000    0.001    0.001 re.py:138(match)
        1    0.000    0.000    0.000    0.000 urllib2.py:181(__init__)
       28    0.000    0.000    0.000    0.000 httplib.py:860(_output)
        4    0.000    0.000    0.000    0.000 httplib.py:826(close)
        2    0.000    0.000    0.000    0.000 sutils.py:59(add_http)
       30    0.000    0.000    0.000    0.000 rfc822.py:214(islast)
        4    0.000    0.000    0.000    0.000 httplib.py:517(_check_close)
        4    0.000    0.000    0.000    0.000 httplib.py:766(_get_hostport)
        3    0.000    0.000    0.000    0.000 sre_compile.py:228(_compile_charset)
        5    0.000    0.000    0.000    0.000 sre_parse.py:268(_escape)
        4    0.000    0.000    0.000    0.000 urllib.py:1221(unquote)
       44    0.000    0.000    0.000    0.000 sre_parse.py:137(__len__)
        1    0.000    0.000    2.948    2.948 test_stuff.py:9(main)
        2    0.000    0.000    0.000    0.000 __init__.py:294(loads)
       30    0.000    0.000    0.000    0.000 rfc822.py:224(iscomment)
        4    0.000    0.000    0.000    0.000 httplib.py:1044(_set_content_length)
        4    0.000    0.000    0.000    0.000 urllib.py:1069(unwrap)
        1    0.000    0.000    2.576    2.576 api.py:68(__init__)
       13    0.000    0.000    0.000    0.000 urllib2.py:528(__lt__)
       10    0.000    0.000    0.000    0.000 urllib2.py:273(get_full_url)
       10    0.000    0.000    0.000    0.000 sre_compile.py:546(isstring)
        4    0.000    0.000    2.408    0.602 httplib.py:1025(endheaders)
        8    0.000    0.000    0.000    0.000 urllib2.py:314(add_header)
        1    0.000    0.000    0.372    0.372 api.py:157(get_images)
       19    0.000    0.000    0.000    0.000 message.py:104(isEnabledFor)
       12    0.000    0.000    0.000    0.000 urllib2.py:1173(<genexpr>)
        8    0.000    0.000    0.000    0.000 ssl.py:634(_check_connected)
        7    0.000    0.000    0.000    0.000 message.py:222(verbose)
        5    0.000    0.000    0.000    0.000 sre_parse.py:67(__init__)
        1    0.000    0.000    2.576    2.576 api.py:100(load_image)
        1    0.000    0.000    0.000    0.000 urllib2.py:555(http_error_default)
        8    0.000    0.000    0.000    0.000 socket.py:296(flush)
        8    0.000    0.000    0.000    0.000 urllib2.py:322(has_header)
        8    0.000    0.000    0.000    0.000 sre_parse.py:74(opengroup)
        4    0.000    0.000    0.000    0.000 urllib.py:1054(_is_unicode)
        4    0.000    0.000    0.000    0.000 ssl.py:352(__init__)
        2    0.000    0.000    0.000    0.000 UserDict.py:57(items)
        8    0.000    0.000    0.000    0.000 urllib2.py:318(add_unredirected_header)
       20    0.000    0.000    0.000    0.000 ssl.py:630(_checkClosed)
       11    0.000    0.000    0.000    0.000 sre_parse.py:145(__setitem__)
        6    0.000    0.000    0.000    0.000 urlparse.py:206(<genexpr>)
        4    0.000    0.000    0.000    0.000 urllib2.py:256(get_method)
        8    0.000    0.000    0.000    0.000 urllib2.py:267(has_data)
        4    0.000    0.000    0.000    0.000 ssl.py:617(context)
        1    0.000    0.000    0.000    0.000 urllib2.py:739(__init__)
        1    0.000    0.000    0.000    0.000 base.py:96(__init__)
        8    0.000    0.000    0.000    0.000 sre_parse.py:85(closegroup)
        4    0.000    0.000    0.000    0.000 httplib.py:785(set_debuglevel)
        4    0.000    0.000    0.000    0.000 urllib.py:1023(info)
        1    0.000    0.000    0.000    0.000 urllib2.py:1237(__init__)
        1    0.000    0.000    0.000    0.000 urllib2.py:337(__init__)
        1    0.000    0.000    0.000    0.000 rfc822.py:444(__contains__)
        8    0.000    0.000    0.000    0.000 urllib2.py:521(add_parent)
        4    0.000    0.000    0.000    0.000 urllib2.py:293(get_selector)
        4    0.000    0.000    0.000    0.000 urllib2.py:305(has_proxy)
        2    0.000    0.000    0.000    0.000 urllib2.py:1119(__init__)
        1    0.000    0.000    0.000    0.000 rfc822.py:391(__getitem__)
        1    0.000    0.000    0.000    0.000 UserDict.py:103(__contains__)
        1    0.000    0.000    0.000    0.000 api.py:94(_init_headers)
        0    0.000             0.000          profile:0(profiler)

vsoch · 2017-04-25T22:46:43Z

sorry - where is the base case, and where is the list of times? The logger helper was not intended for this. I would recommend trying with image poldracklab/mriqc and please provide a base test case (serial download) minimal 5 times, and then the comparison with the multiprocessing, for also 5 times. And to make digestion of the result easy, you can just have two python lists, eg:

base: [A,B,C,D,E]
multi [A,B,C,D,E]

thanks!

…d fixing progress bars!

vsoch · 2017-04-26T02:05:22Z

ok, updates are the following! We wanted to be able to separate the downloading of layers from the changing of permissions, because right now they are packaged together, and each takes a substantial amount of time. However, you can imagine it would be less than ideal to do two "batches" like:

Multiprocessing task 1: Download huge chunk of layers, since it's atomic, each is saved with some .tmp extension.
Pass this list to Multiprocessing task 2: change permissions of layers, save with final name

because let's say we have 15 files, it takes 10 minutes to get to number 10 and then for step 1, the entire thing dies. We have to start over. That's annoying, and that's why we have it (now) like:

Download A, change permissions A --> final A
Download B, change permissions B --> final B

so the challenge is - how to split up changing permissions from downloading without making it a PITA if you fail mid way? I decided to do the following.

Dynamic Multiprocessing Client

What I basically wanted to do is allow for the multiprocessing client to, midway running things, add another "thing" to his queue, the "thing" being the file that is downloaded, but still needs permissions fixed. To support this, I made the MultiProcess client take an optional second function, func2 and given that it's defined, it doubles the number of tasks to complete:

        # If two functions are run per task, double total jobs
        if func2 is not None:
            total = total * 2

then, as before, we create a multiprocessing pool to start the first set of tasks to download the files.

            pool = multiprocessing.Pool(self.workers,init_worker)

            self.start()
            for task in tasks:
                result = pool.apply_async(multi_wrapper,
                                          multi_package(func,[task]))
                results.append(result)
                level1.append(result._job)

but you'll notice I'm not appending these ids (result._job is an int) to a level1 list, and I do this so later I can check if a result object (one of the worker job things in the queue) has been processed through the second function. To do this, I then pop each result off the queue, and if it's a level1, and if a second function (eg change permissions) is defined, I dynamically add this new job to the multiprocessing pool:

            while len(results) > 0:
                result = results.pop()
                result.wait()
                bot.show_progress(progress,total,length=35,prefix=prefix)
                progress+=1
                prefix = "[%s/%s]" %(progress,total)

                # Pass the result through a second function?
                if func2 is not None and result._job in level1:
                    result = pool.apply_async(multi_wrapper,
                                              multi_package(func2,[(result.get(),)]))
                    results.append(result)
                else:
                    finished.append(result.get())

Then we have some catches to make sure keyboard interrupts are caught, and we return the list of finished. To support this, the different functions for download and changing permissions are now under docker/tasks, and the get_layer function for the docker client doesn't change permissions by default.

I think/hope this should speed things up a little bit! I haven't tested that all the results are still passing, but will update the PR with fixes for anything that doesn't.

Progress Bar

The progress bar can now minimally show the number of total tasks (downloads and permissions) as separate things instead of them being bundled into 1. I've also fixed it so the shub downloads will have the progress bar again. I changed the > symbol to a | because the arrow creates a sense of "this thing is moving" for the user, and it's more of a "this is a marker for where we are" now.

vsoch · 2017-04-26T02:59:17Z

https://asciinema.org/a/117638?speed=3

…PYTHREADS

gmkurtzer · 2017-04-26T04:19:07Z

Fantastic, merged!

vsoch added 3 commits April 24, 2017 03:11

adding multiprocessing for downloading

0de41e4

modified: libexec/python/shub/api.py

8628bfe

modified: libexec/python/base.py

463f36f

vsoch added 2 commits April 25, 2017 21:06

adding fixing of permissions to be separate multiprocessing tasks, an…

851c79e

…d fixing progress bars!

adding new/separate tests for tasks in docker

9c416d1

vsoch added 2 commits April 25, 2017 22:15

more tests changes

3ea5c8d

oups

566a1a5

vsoch added 2 commits April 25, 2017 23:41

adding SINGULARITY_WORKERS --> from environment variable SINGULARITY_…

257150d

…PYTHREADS

changing order of layers to be as before

e8b5834

gmkurtzer merged commit e8b5834 into apptainer:development Apr 26, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add/multiprocessing #634

Add/multiprocessing #634

vsoch commented Apr 24, 2017

vsoch commented Apr 24, 2017

vsoch commented Apr 24, 2017

vsoch commented Apr 24, 2017

vsoch commented Apr 25, 2017

vsoch commented Apr 25, 2017

ArangoGutierrez commented Apr 25, 2017

vsoch commented Apr 25, 2017

vsoch commented Apr 26, 2017

vsoch commented Apr 26, 2017

gmkurtzer commented Apr 26, 2017

Add/multiprocessing #634

Add/multiprocessing #634

Conversation

vsoch commented Apr 24, 2017

Progress Bar

Testing

vsoch commented Apr 24, 2017

vsoch commented Apr 24, 2017

vsoch commented Apr 24, 2017

vsoch commented Apr 25, 2017

vsoch commented Apr 25, 2017

ArangoGutierrez commented Apr 25, 2017

vsoch commented Apr 25, 2017

vsoch commented Apr 26, 2017

Dynamic Multiprocessing Client

Progress Bar

vsoch commented Apr 26, 2017

gmkurtzer commented Apr 26, 2017