WebDAV File Descriptor Leak
Hello, We've run into a problem where we get messages like this in our Zope logs: 2003-05-23T18:56:08 PROBLEM(100) ZServer Server accept() threw an exception we occasionally get a lot of these and then restart Zope on the ZEO Client and everything is okay. After a little more investigation we found that these occur when we run out of File Descriptors. So, why are we running out of file descriptors??? Tracked it down to this: each time a WebDAV client connects to zope cluster a temporary file is created. lsof shows the following: python 19005 httpd 1016u REG 0,9 227 15857725 /var/tmp/@19004.1930 (deleted) python 19005 httpd 1017u REG 0,9 227 15857727 /var/tmp/@19004.1931 (deleted) python 19005 httpd 1018u REG 0,9 227 15857732 /var/tmp/@19003.1933 (deleted) python 19005 httpd 1019u REG 0,9 227 15857738 /var/tmp/@19003.1934 (deleted) python 19005 httpd 1020u REG 0,9 227 15857740 /var/tmp/@19003.1935 (deleted) python 19005 httpd 1021u REG 0,9 227 15857743 /var/tmp/@19003.1936 (deleted) python 19005 httpd 1022u REG 0,9 227 15857745 /var/tmp/@19003.1937 (deleted) python 19005 httpd 1023u REG 0,9 227 15857886 /var/tmp/@19003.1956 (deleted) they are all roughly the same size. There seems to be a file descriptor leak. Is this a known problem? We are running Zope 2.5.1 right now. Any ideas? Thanks, -Brian
Can you reproduce the behaviour with 2.6.2? -aj --On Dienstag, 27. Mai 2003 11:07 Uhr -0500 Brian Brinegar <brinegar@pier.ecn.purdue.edu> wrote:
Hello,
We've run into a problem where we get messages like this in our Zope logs:
2003-05-23T18:56:08 PROBLEM(100) ZServer Server accept() threw an exception
we occasionally get a lot of these and then restart Zope on the ZEO Client and everything is okay. After a little more investigation we found that these occur when we run out of File Descriptors. So, why are we running out of file descriptors???
Tracked it down to this: each time a WebDAV client connects to zope cluster a temporary file is created. lsof shows the following:
python 19005 httpd 1016u REG 0,9 227 15857725 /var/tmp/@19004.1930 (deleted) python 19005 httpd 1017u REG 0,9 227 15857727 /var/tmp/@19004.1931 (deleted) python 19005 httpd 1018u REG 0,9 227 15857732 /var/tmp/@19003.1933 (deleted) python 19005 httpd 1019u REG 0,9 227 15857738 /var/tmp/@19003.1934 (deleted) python 19005 httpd 1020u REG 0,9 227 15857740 /var/tmp/@19003.1935 (deleted) python 19005 httpd 1021u REG 0,9 227 15857743 /var/tmp/@19003.1936 (deleted) python 19005 httpd 1022u REG 0,9 227 15857745 /var/tmp/@19003.1937 (deleted) python 19005 httpd 1023u REG 0,9 227 15857886 /var/tmp/@19003.1956 (deleted)
they are all roughly the same size. There seems to be a file descriptor leak. Is this a known problem? We are running Zope 2.5.1 right now.
Any ideas?
Thanks, -Brian
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Don't have a 2.6.2 setup right now. It will take it a while for us to get a system running Zope 2.6.2 up. Though we are planning to migrate to Zope 2.6.2 in early July. Are there changes in Zope 2.6.2 that would effect this? -Brian Andreas Jung wrote:
Can you reproduce the behaviour with 2.6.2?
-aj
--On Dienstag, 27. Mai 2003 11:07 Uhr -0500 Brian Brinegar <brinegar@pier.ecn.purdue.edu> wrote:
Hello,
We've run into a problem where we get messages like this in our Zope logs:
2003-05-23T18:56:08 PROBLEM(100) ZServer Server accept() threw an exception
we occasionally get a lot of these and then restart Zope on the ZEO Client and everything is okay. After a little more investigation we found that these occur when we run out of File Descriptors. So, why are we running out of file descriptors???
Tracked it down to this: each time a WebDAV client connects to zope cluster a temporary file is created. lsof shows the following:
python 19005 httpd 1016u REG 0,9 227 15857725 /var/tmp/@19004.1930 (deleted) python 19005 httpd 1017u REG 0,9 227 15857727 /var/tmp/@19004.1931 (deleted) python 19005 httpd 1018u REG 0,9 227 15857732 /var/tmp/@19003.1933 (deleted) python 19005 httpd 1019u REG 0,9 227 15857738 /var/tmp/@19003.1934 (deleted) python 19005 httpd 1020u REG 0,9 227 15857740 /var/tmp/@19003.1935 (deleted) python 19005 httpd 1021u REG 0,9 227 15857743 /var/tmp/@19003.1936 (deleted) python 19005 httpd 1022u REG 0,9 227 15857745 /var/tmp/@19003.1937 (deleted) python 19005 httpd 1023u REG 0,9 227 15857886 /var/tmp/@19003.1956 (deleted)
they are all roughly the same size. There seems to be a file descriptor leak. Is this a known problem? We are running Zope 2.5.1 right now.
Any ideas?
Thanks, -Brian
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
--On Dienstag, 27. Mai 2003 11:26 Uhr -0500 Brian Brinegar <brinegar@pier.ecn.purdue.edu> wrote:
Don't have a 2.6.2 setup right now. It will take it a while for us to get a system running Zope 2.6.2 up. Though we are planning to migrate to Zope 2.6.2 in early July. Are there changes in Zope 2.6.2 that would effect this?
No idea but there have been a bunch of changes so it might be fixed. I do not want to spent too much time for bug hunting in older versions. -aj
Andreas, Rather than waiting to setup a new ZEO to test this out I decided to poke around at the linux releases that are available. I was able to reproduce our problem using the 2.5.1 release as well as the 2.6.0 release. It appears to be fixed in the 2.6.2b1 release. Until we are able to move to 2.6.2 I will work on a way of monitoring this on or production server. Thank you, Brian Brinegar ECN Web Systems Developer Purdue University Andreas Jung wrote:
--On Dienstag, 27. Mai 2003 11:26 Uhr -0500 Brian Brinegar <brinegar@pier.ecn.purdue.edu> wrote:
Don't have a 2.6.2 setup right now. It will take it a while for us to get a system running Zope 2.6.2 up. Though we are planning to migrate to Zope 2.6.2 in early July. Are there changes in Zope 2.6.2 that would effect this?
No idea but there have been a bunch of changes so it might be fixed. I do not want to spent too much time for bug hunting in older versions.
-aj
Brian Brinegar wrote:
Though we are planning to migrate to Zope 2.6.2 in early July. Are there changes in Zope 2.6.2 that would effect this?
I seem to recall CVS commit messages to the effect.
/var/tmp/@19004.1930 (deleted)
It should be noted, on a multiuser machine, /var/tmp is not a safe place to store Python 2.2.2 and earlier's insecure tempfile.py made files. Setting the TMPDIR variable for Zope to a directory which only the zope user may write to is recommended to avoid a potential DoS vulnerability. My understanding is that this is finally addressed in python 2.3. -- Jamie Heilman http://audible.transient.net/~jamie/ "We must be born with an intuition of mortality. Before we know the words for it, before we know there are words, out we come bloodied and squalling with the knowledge that for all the compasses in the world, there's only one direction, and time is its only measure." -Rosencrantz
Andreas Jung wrote at 2003-5-27 18:11 +0200:
Can you reproduce the behaviour with 2.6.2?
We have the same problem with 2.6.1 without WebDAV. Thus, the problem is probably not WebDAV related (but rather related to file uploading). Dieter
I checked the corresponding code and the temporary files should be closed automatically when the upload was successful (the __del__() method of the TemporaryFile class closes the file). The leak might come from unfinished uploads. In this case the iTemporaryFile instance is not destroyed. -aj --On Mittwoch, 28. Mai 2003 22:27 Uhr +0200 Dieter Maurer <dieter@handshake.de> wrote:
Andreas Jung wrote at 2003-5-27 18:11 +0200:
Can you reproduce the behaviour with 2.6.2?
We have the same problem with 2.6.1 without WebDAV. Thus, the problem is probably not WebDAV related (but rather related to file uploading).
Dieter
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
It seems to occur when WebDAV clients initially connect, not during file transfer. I was able to produce the problem with Cadaver as well as several other WebDAV clients. -Brian Andreas Jung wrote:
I checked the corresponding code and the temporary files should be closed automatically when the upload was successful (the __del__() method of the TemporaryFile class closes the file). The leak might come from unfinished uploads. In this case the iTemporaryFile instance is not destroyed.
-aj
--On Mittwoch, 28. Mai 2003 22:27 Uhr +0200 Dieter Maurer <dieter@handshake.de> wrote:
Andreas Jung wrote at 2003-5-27 18:11 +0200:
Can you reproduce the behaviour with 2.6.2?
We have the same problem with 2.6.1 without WebDAV. Thus, the problem is probably not WebDAV related (but rather related to file uploading).
Dieter
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
Since I can not reproduce the behaviour I suggest that you should patch the tempfile module and add some debug code. Add some logging to see when new temporary file are created and when they are deleted. And it should be possible to figure the Zope part that creates the corresponding temporary. files. -aj --On Donnerstag, 29. Mai 2003 14:31 Uhr -0500 Brian Brinegar <brinegar@pier.ecn.purdue.edu> wrote:
It seems to occur when WebDAV clients initially connect, not during file transfer. I was able to produce the problem with Cadaver as well as several other WebDAV clients.
-Brian
Andreas Jung wrote:
I checked the corresponding code and the temporary files should be closed automatically when the upload was successful (the __del__() method of the TemporaryFile class closes the file). The leak might come from unfinished uploads. In this case the iTemporaryFile instance is not destroyed.
-aj
--On Mittwoch, 28. Mai 2003 22:27 Uhr +0200 Dieter Maurer <dieter@handshake.de> wrote:
Andreas Jung wrote at 2003-5-27 18:11 +0200:
Can you reproduce the behaviour with 2.6.2?
We have the same problem with 2.6.1 without WebDAV. Thus, the problem is probably not WebDAV related (but rather related to file uploading).
Dieter
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
_______________________________________________ Zope-Dev maillist - Zope-Dev@zope.org http://mail.zope.org/mailman/listinfo/zope-dev ** No cross posts or HTML encoding! ** (Related lists - http://mail.zope.org/mailman/listinfo/zope-announce http://mail.zope.org/mailman/listinfo/zope )
On Thu, May 29, 2003 at 09:28:16PM +0200, Andreas Jung wrote: | I checked the corresponding code and the temporary files should be closed | automatically when the upload was successful (the __del__() method of the | TemporaryFile | class closes the file). The leak might come from unfinished uploads. In | this case the | iTemporaryFile instance is not destroyed. I remember that Shane fixed a leak related to File uploads a few months ago. Dunno if it was related to file descriptors, but AFAIR, it was fixed just on HEAD. Correct me if Im wrong. []'s -- Sidnei da Silva (dreamcatcher) <sidnei@x3ng.com.br> X3ng Web Technology <http://www.x3ng.com.br> GNU/Linux user 257852 Debian GNU/Linux 3.0 (Sid) 2.4.20-powerpc ppc I'm still waiting for the advent of the computer science groupie.
--On Donnerstag, 29. Mai 2003 16:38 Uhr -0300 Sidnei da Silva <sidnei@x3ng.com> wrote:
On Thu, May 29, 2003 at 09:28:16PM +0200, Andreas Jung wrote: | I checked the corresponding code and the temporary files should be closed | automatically when the upload was successful (the __del__() method of | the TemporaryFile | class closes the file). The leak might come from unfinished uploads. In | this case the | iTemporaryFile instance is not destroyed.
I remember that Shane fixed a leak related to File uploads a few months ago. Dunno if it was related to file descriptors, but AFAIR, it was fixed just on HEAD. Correct me if Im wrong.
I made my tests on the HEAD. -aj
Sidnei da Silva wrote:
On Thu, May 29, 2003 at 09:28:16PM +0200, Andreas Jung wrote: | I checked the corresponding code and the temporary files should be closed | automatically when the upload was successful (the __del__() method of the | TemporaryFile | class closes the file). The leak might come from unfinished uploads. In | this case the | iTemporaryFile instance is not destroyed.
I remember that Shane fixed a leak related to File uploads a few months ago. Dunno if it was related to file descriptors, but AFAIR, it was fixed just on HEAD. Correct me if Im wrong.
It was directly related to file descriptors, and I fixed it both on the head and the branch, although it wasn't specific to WebDAV. Brian, please try the latest Zope-2_6-branch. It includes the following easy-to-backport changes: http://cvs.zope.org/Zope/lib/python/ZServer/HTTPServer.py.diff?r1=1.45&r2=1.... http://cvs.zope.org/Zope/lib/python/ZPublisher/HTTPRequest.py.diff?r1=1.89&r... Shane
participants (6)
-
Andreas Jung -
Brian Brinegar -
Dieter Maurer -
Jamie Heilman -
Shane Hathaway -
Sidnei da Silva