[Zope] Zope or Python blocking on select()

Tue Feb 8 05:29:00 EST 2005

Hello,

Running Zwiki 0.36 on Zope 2.7.4-0 on Python 2.4, glibc-2.3.4-3, kernel 
2.4.22-nptl (fedora core 1).

Whenever we hit a ZWiki page, there is a delay of 8 seconds before the 
first page is sent.  Subsequent objects for that request are sent in 
reasonable (i.e. sub-second) times.  Every individual page request seems 
to cause this delay.  I have tried all 3 ways of setting the 
LD_ASSUME_KERNEL variable, tried recompiling Python using the 
'--with-lib=' option for the different thread libraries, tried Python 
2.3.3, and all this still gives the same result - a nasty 8 seconds delay.

Has anyone else run into a delay like this?  Is anyone using a similar 
kernel/Python/Zope combination successfully?

I have pasted a brief excerpt from strace of my Python process, any 
advice on what may be happening would be welcome. 

The 8 second delay occurs after the select call '18:50:38.256285 
select(16, [4 5 8 15], [], [4 5 8 15], {30, 0}) = 1 (in [8], left {21, 
930000})'

Thanks,
David

6541  18:50:38.231673 recv(15, "GET /am/DesignIterationStories 
HTTP/1.1\r\nAccept: image/gif, image/x-
xbitmap, image/jpeg, image/pjpeg, application/x-shockwave-flash, 
application/vnd.ms-excel, application
/vnd.ms-powerpoint, application/msword, */*\r\nReferer: 
https://our.server.com/am/FrontPage\r\nAcc
ept-Language: en-us\r\nAccept-Encoding: gzip, deflate\r\nUser-Agent: 
Mozilla/4.0 (compatible; MSIE 6.0
; Windows NT 5.1)\r\nHost: our.server.com:443\r\nConnection: 
Keep-Alive\r\nCookie: zwiki_displaymo
de=\"simple\"; 
tree-s=\"eJzTyCkw5NLIKTDiClZ3hANXW3WuAmOuRKCECUjWFEnW2cQXJGvGlQiSNkeWMQbLWABlEhP1AO-ZFk
w\"\r\nAuthorization: Basic ZHN3aWZ0OjR0aGZsMDBy\r\nX-SSL-cipher: 
RC4-MD5                 SSLv3 Kx=RSA
      Au=RSA  Enc=RC4(128)  Mac=MD5 \r\nX-Forwarded-For: 
192.168.1.20\r\n\r\n", 4096, 0) = 729
6541  18:50:38.233418 gettimeofday({1107831038, 233651}, NULL) = 0
6541  18:50:38.235096 kill(6545, SIGRTMIN) = 0
6541  18:50:38.235658 kill(6545, SIGRTMIN) = 0
6541  18:50:38.253015 rt_sigprocmask(SIG_SETMASK, NULL, [RTMIN], 8) = 0
6541  18:50:38.253668 rt_sigsuspend([] <unfinished ...>
6541  18:50:38.254468 --- SIGRTMIN (Unknown signal 32) @ 0 (0) ---
6541  18:50:38.254928 <... rt_sigsuspend resumed> ) = -1 EINTR 
(Interrupted system call)
6541  18:50:38.255248 sigreturn()       = ? (mask now [RTMIN])
6541  18:50:38.255882 kill(6545, SIGRTMIN) = 0
6541  18:50:38.256285 select(16, [4 5 8 15], [], [4 5 8 15], {30, 0}) = 
1 (in [8], left {21, 930000})
6541  18:50:46.331142 read(8, "x", 8192) = 1
6541  18:50:46.331775 select(16, [4 5 8 15], [15], [4 5 8 15], {30, 0}) 
= 1 (out [15], left {30, 0})
6541  18:50:46.332720 send(15, "HTTP/1.1 200 OK\r\nServer: Zope/(Zope 
2.7.4-0, python 2.4.0, linux2) Z
Server/1.1\r\nDate: Tue, 08 Feb 2005 02:50:46 GMT\r\nContent-Length: 
21296\r\nContent-Type: text/html;
 charset=utf-8\r\nConnection: close\r\n\r\n<!DOCTYPE html PUBLIC 
\"-//W3C//DTD XHTML 1.0 Transitional/
/EN\" 
\"http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd\">\n<html 
xmlns=\"http://www.w3.org/19