[Errno 24] Too many open files

84 views

Skip to first unread message

RjOllos

unread,

Jun 28, 2016, 10:22:35 PM6/28/16

to Trac Users

This is a Trac with Nginx and fcgi configuration on Debian 8.5, which has always been problematic but has become very unstable over the past few days. I searched existing issues (1), but am currently out of ideas. Excerpt from log below, along with configuration.

Unfortunately I don't know Nginx or fcgi very well. I'm considering moving to Apache with mod_wsgi. Any hints about what the problem might be would be appreciated.

- Ryan

(1) https://trac.edgewall.org/search?q=%27too+many+open+files%27&noquickjump=1&ticket=on

2016-06-28 20:40:23,181 Trac[main] ERROR: Internal Server Error: <RequestWithSession "GET '/query?milestone=1.4.1&group=status&order=type&row=description'">, referrer None

Traceback (most recent call last):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 562, in _dispatch_request

dispatcher.dispatch(req)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 269, in dispatch

iterable=chrome.use_chunked_encoding)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/chrome.py", line 1114, in render_template

encoding='utf-8')

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 184, in render

return encode(generator, method=method, encoding=encoding, out=out)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/output.py", line 58, in encode

for chunk in iterator:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/output.py", line 350, in __call__

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/output.py", line 829, in __call__

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/output.py", line 669, in __call__

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/output.py", line 774, in __call__

for kind, data, pos in chain(stream, [(None, None, None)]):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/output.py", line 594, in __call__

for ev in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/chrome.py", line 1320, in _strip_accesskeys

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/chrome.py", line 1309, in _generate

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/filters/transform.py", line 706, in _unmark

for mark, event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/filters/transform.py", line 1101, in __call__

for mark, event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/filters/transform.py", line 118, in __iter__

event = self.stream.next()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/filters/transform.py", line 734, in __call__

for mark, event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/filters/transform.py", line 702, in _mark

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 618, in _include

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 378, in _match

ctxt, start=idx + 1, **vars):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 378, in _match

ctxt, start=idx + 1, **vars):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 362, in _match

content = list(content)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 618, in _include

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 326, in _match

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 315, in _strip

event = next()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 558, in _flatten

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/path.py", line 588, in _generate

subevent = next()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 618, in _include

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 315, in _strip

event = next()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 558, in _flatten

for kind, data, pos in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/core.py", line 289, in _ensure

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/path.py", line 588, in _generate

subevent = next()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 618, in _include

for event in stream:

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/markup.py", line 315, in _strip

event = next()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 578, in _flatten

result = _eval_expr(data, ctxt, vars)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/base.py", line 289, in _eval_expr

retval = expr.evaluate(ctxt)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/genshi/template/eval.py", line 177, in evaluate

return eval(self.code, _globals, {'__data__': data})

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/templates/query_results.html", line 112, in <Expression u'wiki_to_html(ticket_context, result[r])'>

${wiki_to_html(ticket_context, result[r])}

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1586, in format_to_html

return HtmlFormatter(env, context, wikidom).generate(escape_newlines)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1541, in generate

escape_newlines)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1323, in format

result = re.sub(self.wikiparser.rules, self.replace, line)

File "<obfuscated>/private/pve/lib/python2.7/re.py", line 155, in sub

return _compile(pattern, flags).sub(repl, string, count)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1241, in replace

replacement = self.handle_match(fullmatch)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1234, in handle_match

return external_handler(self, match, fullmatch)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/versioncontrol/web_ui/changeset.py", line 1040, in <lambda>

y, z))

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/versioncontrol/web_ui/changeset.py", line 1072, in _format_changeset_link

changeset = repos.get_changeset(rev)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/git_fs.py", line 85, in get_changeset

return GitCachedChangeset(self, self.normalize_rev(rev), self.env)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/git_fs.py", line 56, in normalize_rev

normrev = self.repos.git.verifyrev(rev)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/PyGIT.py", line 718, in verifyrev

rc = self.repo.rev_parse('--verify', rev).strip()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/PyGIT.py", line 140, in __execute

p = self.__pipe(git_cmd, stdout=PIPE, stderr=PIPE, *cmd_args)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/PyGIT.py", line 133, in __pipe

close_fds=close_fds, **kw)

File "/usr/lib/python2.7/subprocess.py", line 702, in __init__

errread, errwrite), to_close = self._get_handles(stdin, stdout, stderr)

File "/usr/lib/python2.7/subprocess.py", line 1141, in _get_handles

errread, errwrite = self.pipe_cloexec()

File "/usr/lib/python2.7/subprocess.py", line 1175, in pipe_cloexec

r, w = os.pipe()

OSError: [Errno 24] Too many open files

2016-06-28 20:40:23,400 Trac[main] ERROR: Internal Server Error: <RequestWithSession "GET '/ticket/3048'">, referrer '<obfuscated>'

Traceback (most recent call last):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 562, in _dispatch_request

dispatcher.dispatch(req)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 249, in dispatch

resp = chosen_handler.process_request(req)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/web_ui.py", line 181, in process_request

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/web_ui.py", line 533, in _process_ticket_request

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/model.py", line 71, in __init__

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/api.py", line 281, in get_ticket_fields

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/util/translation.py", line 202, in gettext

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/util/translation.py", line 182, in isactive

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/util/translation.py", line 148, in activate

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/babel/support.py", line 562, in load

IOError: [Errno 24] Too many open files: '<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/locale/en_US/LC_MESSAGES/messages.mo'

Jun Omae

unread,

Jun 29, 2016, 7:13:36 AM6/29/16

to trac-...@googlegroups.com

Hi, Ryan.

<rjo...@gmail.com> wrote on 2016-Jun-29 at 11:22 AM:
> This is a Trac with Nginx and fcgi configuration on Debian 8.5, which has always been problematic but has become very unstable over the past few days. I searched existing issues (1), but am currently out of ideas. Excerpt from log below, along with configuration.
>
> Unfortunately I don't know Nginx or fcgi very well. I'm considering moving to Apache with mod_wsgi. Any hints about what the problem might be would be appreciated.
>
> - Ryan

After [14419], we use PIPEs for stdin/stdout/stderr of Popen. I guess those pipes leak and EMFILE is raised due to rendering many git revisions in tickets' description in custom query. However, the pipes are closed by gc.collect() each request.

Therefore, I think this issue wouldn't be solved by moving to mod_wsgi.

I attach patch which closes the pipes. Could you please try it?

--
Jun Omae <jun...@gmail.com> (大前潤)

close-proc-pipes.diff

RjOllos

unread,

Jun 29, 2016, 9:54:04 AM6/29/16

to Trac Users

Thanks for the patch! I'll apply it today and report back in a few days.

- Ryan

RjOllos

unread,

Jun 30, 2016, 9:22:45 PM6/30/16

to Trac Users

The patched instance has been running more than a day now. It seems to be much more stable, but we did have one brief outage, and the following in the logs:

2016-06-30 12:24:17,136 Trac[main] ERROR: Internal Server Error: <RequestWithSession "GET '/timeline?from=2009-02-10T22%3A09%3A19-05%3A00&precision=second'">, referrer '<obfuscated>'

Traceback (most recent call last):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 562, in _dispatch_request

dispatcher.dispatch(req)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/timeline/templates/timeline.html", line 68, in <Expression u"event.render('description', context)">

${event.render('description', context)}

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/timeline/web_ui.py", line 367, in <lambda>

provider.render_timeline_event(context, field, event)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/web_ui.py", line 418, in render_timeline_event

return descr + format_to(self.env, None, t_context, message)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1577, in format_to

return format_to_oneliner(env, context, wikidom, **options)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1593, in format_to_oneliner

return InlineHtmlFormatter(env, context, wikidom).generate(shorten)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1569, in generate

shorten)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1425, in format

result = re.sub(self.wikiparser.rules, self.replace, result)

File "<obfuscated>/private/pve/lib/python2.7/re.py", line 155, in sub

return _compile(pattern, flags).sub(repl, string, count)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1241, in replace

replacement = self.handle_match(fullmatch)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/wiki/formatter.py", line 1234, in handle_match

return external_handler(self, match, fullmatch)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/versioncontrol/web_ui/changeset.py", line 1040, in <lambda>

y, z))

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/versioncontrol/web_ui/changeset.py", line 1072, in _format_changeset_link

changeset = repos.get_changeset(rev)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/git_fs.py", line 85, in get_changeset

return GitCachedChangeset(self, self.normalize_rev(rev), self.env)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/git_fs.py", line 56, in normalize_rev

normrev = self.repos.git.verifyrev(rev)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/PyGIT.py", line 727, in verifyrev

rc = self.repo.rev_parse('--verify', rev).strip()

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/PyGIT.py", line 147, in __execute

p = self.__pipe(git_cmd, stdout=PIPE, stderr=PIPE, *cmd_args)

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/tracopt/versioncontrol/git/PyGIT.py", line 140, in __pipe

close_fds=close_fds, **kw)

File "/usr/lib/python2.7/subprocess.py", line 710, in __init__

errread, errwrite)

File "/usr/lib/python2.7/subprocess.py", line 1223, in _execute_child

errpipe_read, errpipe_write = self.pipe_cloexec()

File "/usr/lib/python2.7/subprocess.py", line 1175, in pipe_cloexec

r, w = os.pipe()

OSError: [Errno 24] Too many open files

2016-06-30 12:24:34,526 Trac[main] ERROR: Internal Server Error: <RequestWithSession "GET '/timeline?from=2013-02-25T13%3A56%3A35-05%3A00&precision=second'">, referrer '<obfuscated>'

Traceback (most recent call last):

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 562, in _dispatch_request

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/web/main.py", line 249, in dispatch

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/timeline/web_ui.py", line 160, in process_request

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/ticket/web_ui.py", line 244, in get_timeline_filters

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/util/translation.py", line 202, in gettext

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/util/translation.py", line 182, in isactive

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/util/translation.py", line 153, in activate

File "<obfuscated>/private/pve/local/lib/python2.7/site-packages/babel/support.py", line 562, in load

IOError: [Errno 24] Too many open files: '<obfuscated>/private/pve/local/lib/python2.7/site-packages/trac/locale/en_US/LC_MESSAGES/tracini.mo'

2016-06-30 12:24:34,533 Trac[main] ERROR: Internal Server Error: <RequestWithSession "GET '/timeline?from=2012-08-29T17%3A02%3A48-04%3A00&precision=second'">, referrer '<obfuscated>'