OSError Too many open files when log_file = file

[ryanc@…]

My Trac instances have recently been displaying 500 errors to users intermittently, the exceptions being logged are "OSError: [Errno 24] Too many open files".

Even after I greatly raised the open files limit for all users to an absurd value (999999) these exceptions persisted. The max open file limit for the entire system is 327756 though I've never seen lsof return more than 30k lines or so.

The only aberrant thing I've noticed in lsof output is that by far my various Trac instances' log files are the files that appear most frequently, each being listed in 2-3k lines of lsof output.

No matter what I do to the system, after Apache has been running for a certain amount of time these errors begin to manifest themselves.

I've done a fair amount of experimenting to try and narrow down the problem. While Googling I found #8899 which describes similar symptoms to mine on a Windows box. I was able to stop the errors and exceptions by setting log_file = none for all my Trac instances.

I still have a certain amount of logging for other exceptions and errors in my Apache logs but disabling Trac's internal logging facility altogether is not an ideal solution for me.

System details

• Linux OpenVZ VM
• CentOS 6.4
• Python 2.6.6 (python-2.6.6-36.el6.x86_64)
• Apache/2.2.15 (httpd-2.2.15-26.el6.centos.x86_64)
• mod_wsgi/3.3 (WSGIProcessGroup trac WSGIApplicationGroup %{GLOBAL})
• Trac 0.12.4dev-r11051
• 8 Trac instances
• Individual Trac instances have log_file set to log_file = trac.log

Example exception

The modules and directories indicated in the exceptions aren't always the same

2013-03-22 18:27:06,167 Trac[main] ERROR: Internal Server Error: 
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/Trac-0.12.4dev_r11051-py2.6.egg/trac/web/main.py", line 522, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.6/site-packages/Trac-0.12.4dev_r11051-py2.6.egg/trac/web/main.py", line 264, in dispatch
    content_type)
  File "/usr/lib/python2.6/site-packages/Trac-0.12.4dev_r11051-py2.6.egg/trac/web/chrome.py", line 843, in render_template
  File "/usr/lib/python2.6/site-packages/genshi/core.py", line 132, in __or__
  File "/usr/lib/python2.6/site-packages/Trac-0.12.4dev_r11051-py2.6.egg/trac/web/chrome.py", line 999, in inner
  File "/usr/lib/python2.6/site-packages/TicketSidebarProvider-0.0_r10457-py2.6.egg/ticketsidebarprovider/ticketsidebar.py", line 44, in filter_stream
  File "/usr/lib/python2.6/site-packages/TicketMoverPlugin-0.1.1-py2.6.egg/ticketmoverplugin/web_ui.py", line 28, in enabled
  File "/usr/lib/python2.6/site-packages/TicketMoverPlugin-0.1.1-py2.6.egg/ticketmoverplugin/ticketmover.py", line 155, in projects
OSError: [Errno 24] Too many open files: '/opt/trac'

[Jun Omae]

PluginIssue (​th:TicketMoverPlugin). The issue is caused by incorrect use of open_environment. Please report the maintainers of the plugin.

Also,

ticketmoverplugin/ticketmover.py

@@ -155 +155 @@
         for project in _projects:
             path = os.path.join(base_path, project)
             try:
-                env = open_environment(path)
+                env = open_environment(path, use_cache=True)
             except:
                 continue
             perm = PermissionSystem(env)
@@ -176 +176 @@
         # open the environment if it is a string
         if isinstance(env, basestring):
             base_path, _project = os.path.split(self.env.path)
-            env = open_environment(os.path.join(base_path, env))
+            env = open_environment(os.path.join(base_path, env), use_cache=True)
 
         # get the old ticket
         old_ticket = Ticket(self.env, ticket_id)