The behaviour described below is not always reproduced.

The attached test script simply tries to import a couple of dns-python
modules, which in turn import other ones. No code is being executed.
You expect it to exit for less than a second but it does not. Instead,
it hangs when "time" module is being imported (eventually it exits after
a long time).

Attached are stdout log and system call log produced by strace with
timestamps.

I don't know what causes it but I'm getting it on at least two machines
(the second being virtual):


$ cat /etc/fedora-release 
Fedora release 10 (Cambridge)
$ uname -a
Linux kiki 2.6.27.30-170.2.82.fc10.i686.PAE #1 SMP Mon Aug 17 08:24:23
EDT 2009 i686 i686 i386 GNU/Linux
$ python -c "import sys; print sys.version"
2.5.2 (r252:60911, Sep 30 2008, 15:41:38) 
[GCC 4.3.2 20080917 (Red Hat 4.3.2-4)]


$ cat /etc/redhat-release 
CentOS release 5.3 (Final)
$ uname -a
Linux proxy.sc.com 2.6.18-128.el5 #1 SMP Wed Jan 21 10:44:23 EST 2009
i686 i686 i386 GNU/Linux
$ python -c "import sys; print sys.version"
2.4.3 (#1, Jan 21 2009, 01:10:13) 
[GCC 4.1.2 20071124 (Red Hat 4.1.2-42)]

I don't think it's related to dns-python(that's why I am posting it
here) but for reference the version used is 1.7.1.


The timestamps in stdout.log and strace.log clearly show the slowdown:

# strace.log
18:18:53 ioctl(6, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfac06b0) = -1 EINVAL
(Invalid argument)
18:18:53 mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7e4f000
18:18:53 read(6, "F\t\262\276\261s\223I"..., 4096) = 8
18:19:01 read(6, ")v\244\36\v=U\336"..., 4096) = 8
18:19:11 close(6)                       = 0
18:19:11 munmap(0xb7e4f000, 4096)       = 0
18:19:11 gettimeofday({1253891951, 431529}, NULL) = 0

# stdout.log
18:18:53  dns.entropy
18:18:53  time
18:19:11  hashlib
18:19:11  _hashlib

> "No code is being executed"

Hmm, in dns.entropy module (I found the code there:
http://www.dnspython.com/docs/1.7.1/html/dns.entropy-pysrc.html
) line 89 says "pool = EntropyPool()", and the __init__ function opens
and reads bytes from /dev/random.
This is the cause of the slowdown, as is shown by the strace file.

The time module is innocent here.

Stupid me :))
I must have really missed that.

Still I don't understand why the read call takes 10 seconds to complete.

OK, I found the reason and it is the very fact of using /dev/random
which would block if there aren't enough random numbers in queue.
Maybe dns-python should be using /dev/urandom instead (though there
might be reasons for not doing so).

The mystery is revealed.
I am closing the bug.
:)