[IPython-dev] Slow ipython --pylab and ipython notebook startup

Name Name zeitlinie at yahoo.de
Sun Sep 29 11:34:13 EDT 2013


This is a cross-post from stackoverflow. I know, this is not absolutelyPC, but hopefully someone on this list can provide help. 
I have switched from ipython 0.10 to 1.1.0. Now I am experiencing very annoying slow-downs of the startup process.

While `ipython` alone is still up in no time, `ipython --pylab` takes a very slow start, i.e. `~8 secs` (on an Intel(R) Core(TM)2 Duo CPU P9500 @ 2.53GHz system) and even more so the new `ipython notebook` which I did not have in ipython 0.10, namely `~12 secs`.

When I do `strace -o tessi.txt -tt ipython --pylab` I can identify at least sections which seem to be responsible for large chunks of these delays (search for HERE!!). Any help on getting rid of those would very welcome.

For the `--pylab` option, strace's output contains a section which eats away `~5 secs`, and which is not present when starting just ipython, namely

    10:23:24.331968 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=868, ...}) = 0
    10:23:24.332028 socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 9
    10:23:24.332074 connect(9, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = 0
    10:23:24.332152 sendto(9, "\2\0\0\0\4\0\0\0\35\0\0\0MYHOST.DOM.AIN."..., 41, MSG_NOSIGNAL, NULL, 0) = 41
HERE!! -> 10:23:24.332227 poll([{fd=9, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=9, revents=POLLIN|POLLHUP}])
HERE!! -> 10:23:29.336301 read(9, "\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32) = 32
    10:23:29.336533 close(9)                = 0
    10:23:29.336839 close(7)                = 0

where I've replace my actual host name with `MYHOST.DOM.AIN`

In case of `ipython notebook` there seem to be essentially two such regions. The first one seems to be the same as for `ipython --pylab`. The second one takes away another `~4 secs`

    10:39:31.823298 stat("/etc/resolv.conf", {st_mode=S_IFREG|0644, st_size=868, ...}) = 0
    10:39:31.823358 socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 9
    10:39:31.823405 connect(9, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = 0
    10:39:31.823499 sendto(9, "\2\0\0\0\4\0\0\0\35\0\0\0MYHOST.DOM.AIN."..., 41, MSG_NOSIGNAL, NULL, 0) = 41
HERE!! -> 10:39:31.824166 poll([{fd=9, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=9, revents=POLLIN|POLLHUP}])
HERE!! -> 10:39:36.827298 read(9, "\2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 32) = 32
    10:39:36.827503 close(9)                = 0
    10:39:36.827828 close(7)                = 0    
    
    10:39:38.591774 setsockopt(6, SOL_TCP, TCP_NODELAY, [0], 4) = 0
    10:39:38.591922 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}], 4, 0) = 0 (Timeout)
    10:39:38.592007 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}], 4, 0) = 0 (Timeout)
HERE!! -> 10:39:38.592049 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}], 4, 3600000) = ? ERESTART_RESTARTBLOCK (To be restarted)
HERE!! -> 10:39:42.355658 --- SIGINT (Interrupt) @ 0 (0) ---
    10:39:42.355773 write(5, "\0", 1)       = 1
    10:39:42.355916 rt_sigreturn(0x2)       = -1 EINTR (Interrupted system call)
    10:39:42.356113 rt_sigaction(SIGINT, {0x7f26dc0fbfc6, [], SA_RESTORER, 0x7f26dbe5a2d0}, {0x7f26dc0fbfc6, [], SA_RESTORER, 0x7f26dbe5a2d0}, 8) = 0
    10:39:42.356672 clone(child_stack=0x7f26cfb49ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f26cfb4a9d0, tls=0x7f26cfb4a700, child_tidptr=0x7f26cfb4a9d0) = 11084

Any help on how to get rid of these delays would be most welcome.

Finally, and while I'm at it. When I look at strace's remaing output I see, that on startup, ipython tries to open a lot of 'python related' files in places where I would have naively thought that it should never do so, and where my systems python definitely has not been installed? All these many open calls fail. E.g.:

    11:11:26.465594 open("/opt/intel/composerxe-2011.3.174/compiler/lib/intel64/tls/libpython2.7.so.1.0", O_RDONLY) = -1 ENOENT (No such file or directory)
    11:11:26.465646 stat("/opt/intel/composerxe-2011.3.174/compiler/lib/intel64/tls", 0x7fff0efb0100) = -1 ENOENT (No such file or directory)
    
    or
     
    11:11:26.468293 stat("/usr/local/lib/vtk-5.4/tls/x86_64", 0x7fff0efb0100) = -1 ENOENT (No such file or directory)
    11:11:26.468347 open("/usr/local/lib/vtk-5.4/tls/libpython2.7.so.1.0", O_RDONLY) = -1 ENOENT (No such file or directory)

The time total for these calls make up for another significant portion of the remaining slow startup, but I cannot point to a specific time slot. Any idea how to reduce those calls?

Mark
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/ipython-dev/attachments/20130929/0921596d/attachment.html>


More information about the IPython-dev mailing list