Incompatibilty with gunicorn.

AJamesPhillips commented 11 years ago

We have a web app using django and gunicorn, I don't appreciate how gunicorn handles its workers but after the recent changes we're getting:

2013-10-08 12:28:31 [ERROR] gunicorn.error: Error handling request
Traceback (most recent call last):
  File "/home/ubuntu/venv/local/lib/python2.7/site-packages/gunicorn/workers/async.py", line 55, in handle
    self.handle_error(req, client, addr, e)
  File "/home/ubuntu/venv/local/lib/python2.7/site-packages/gunicorn/workers/base.py", line 177, in handle_error
    self.log.exception("Error handling request")
  File "/home/ubuntu/venv/local/lib/python2.7/site-packages/gunicorn/glogging.py", line 219, in exception
    self.error_log.exception(msg, *args)
  File "/usr/lib/python2.7/logging/__init__.py", line 1172, in exception
    self.error(msg, exc_info=1, *args)
  File "/usr/lib/python2.7/logging/__init__.py", line 1166, in error
    self._log(ERROR, msg, args, **kwargs)
  File "/usr/lib/python2.7/logging/__init__.py", line 1258, in _log
    self.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1268, in handle
    self.callHandlers(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 1308, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 748, in handle
    self.emit(record)
  File "/home/ubuntu/venv/src/logentries/logentries/utils.py", line 122, in emit
    self._thread.start()
  File "/usr/lib/python2.7/threading.py", line 488, in start
    raise RuntimeError("threads can only be started once")
RuntimeError: threads can only be started once

If there's any further information I can provide that might help please let me know, also apologies if this is not an issue for le_python, however when we moved to commit 1726b2271b0fa6d9da4332e165f4ae394e4ffd47 it seems to have resolved the problem. We're using gunicorn 18.0, python 2.7, ubuntu, and we're monkey patching gunicorn. from gevent import monkey; monkey.patch_all(subprocess=False)

MarkLC-r7 commented 11 years ago

Hi Alexander, Sorry about that, I'll look into this as soon as I can. The strange thing is the recent change was to prevent the stacktrace that you pasted which was occurring to the user who made the pull request, whereby now it shouldn't reach the thread.start() more than once if the thread is already started. Thanks for the details about your stack. I'll keep you updated on here

AJamesPhillips commented 11 years ago

No worries. This was the change that caused the problem, interesting that it should fix in one and break in another setup.

bluebomber commented 10 years ago

This commit has introduced a similar problem (it isn't gunicorn related, but we get the same RuntimeError: threads can only be started once exception) for us; @MarkLC , do you have any opinion about "which way" is correct, with respect to how _started is defined/used? Undoing this change seems to fix the problem for us, but it may inadvertently reproduce it in the same place where the original user was experiencing it...

bluebomber commented 10 years ago

@AJamesPhillips , @MarkLC , I just obtained some more information about our particular problem here: We use the Celery distributed task scheduler, and if we start our Celery workers with the option FORCE_EXECV=True, then we do not get this error. If we do not pass the option (the default is False), we get this error. Something about the Celery threading and Logentries threading doesn't play well together, evidently...

akarl commented 9 years ago

We are getting this error when running Celery + New Relic + Logentries.

» 14:18:57.838  {
    "name": "celery.redirected",
    "message": "LE: Starting Logentries Asynchronous Socket Appender",
    "asctime": "2014-12-11 14:18:57,767",
    "levelname": "WARNING",
    "pathname": "[...]/local/lib/python2.7/site-packages/celery/utils/log.py",
    "lineno": 278
}
» 14:18:57.881  {
    "name": "celery.worker",
    "message": "Unrecoverable error: RuntimeError('threads can only be started once',)",
    "asctime": "2014-12-11 14:18:57,768",
    "levelname": "ERROR",
    "pathname": "[...]/local/lib/python2.7/site-packages/celery/worker/__init__.py",
    "lineno": 210
}

StephenHynes7 commented 9 years ago

Can you try the latest version ? https://pypi.python.org/pypi/Logentries

yrunts commented 9 years ago

Error is reproducible when running workers using Celery.

  File "/usr/lib/python3.4/logging/__init__.py", line 1260, in info
    self._log(INFO, msg, args, **kwargs)
  File "/usr/lib/python3.4/logging/__init__.py", line 1395, in _log
    self.handle(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 1405, in handle
    self.callHandlers(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 1467, in callHandlers
    hdlr.handle(record)
  File "/usr/lib/python3.4/logging/__init__.py", line 839, in handle
    self.emit(record)
  File "/vagrant/.env/lib/python3.4/site-packages/logentries/utils.py", line 184, in emit
    self._thread.start()
  File "/usr/lib/python3.4/threading.py", line 846, in start
    raise RuntimeError("threads can only be started once")
RuntimeError: threads can only be started once

rsaftoiu commented 9 years ago

Seeing the same issue with Logentries==0.7, Django==1.4.20, django-celery==3.1.10:

Traceback (most recent call last): File "/home/fedora/deploy/master/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task R = retval = fun(_args, _kwargs) File "/home/fedora/deploy/master/lib/python2.7/site-packages/celery/app/trace.py", line 437, in protected_call return self.run(_args, _kwargs) File "/home/fedora/deploy/master/webapp/shopventoryapp/common/tasks.py", line 110, in run result, exception = self.do_timed_work(_args, _kwargs) File "/home/fedora/deploy/master/webapp/shopventoryapp/common/tasks.py", line 132, in do_timed_work kwargs)) File "/usr/lib64/python2.7/logging/init.py", line 1182, in exception self.error(msg, _args, _kwargs) File "/usr/lib64/python2.7/logging/init.py", line 1175, in error self._log(ERROR, msg, args, kwargs) File "/usr/lib64/python2.7/logging/init.py", line 1268, in _log self.handle(record) File "/usr/lib64/python2.7/logging/init.py", line 1278, in handle self.callHandlers(record) File "/usr/lib64/python2.7/logging/init.py", line 1318, in callHandlers hdlr.handle(record) File "/usr/lib64/python2.7/logging/init**.py", line 749, in handle self.emit(record) File "/home/fedora/deploy/master/lib/python2.7/site-packages/logentries/utils.py", line 184, in emit self._thread.start() File "/usr/lib64/python2.7/threading.py", line 740, in start raise RuntimeError("threads can only be started once") RuntimeError: threads can only be started once

hihell commented 9 years ago

same issue with logentries 0.7 and flask

drgarcia1986 commented 9 years ago

Same here with logentries 0.8 + aiohttp + gunicorn

drgarcia1986 commented 9 years ago

To solve this issue I had to make a pass on the exception

             except RuntimeError: # It's already started.
-                if not self._thread.is_alive():
-                    raise
+                pass

chrisguidry commented 9 years ago

Likewise here, just using multiprocessing in Python 2.7 and the logentries 0.15 Python client.

Sandeep4 commented 9 years ago

Same problem with multiple processes in python.

Sandeep4 commented 9 years ago

Does not happen if we don't use logging in the parent process.

advance512 commented 8 years ago

We had the same issue using 0.15.

Problem was that we called:

import gevent
import gevent.monkey
gevent.monkey.patch_all()

after calling the Logentries handler. This happened in a bastardized piece of code, that was a mix of several other projects.. and so this happened.

Interestingly, it didn't happen on the dev machine, but it did in a cloud env.

Not sure why.

drgarcia1986 commented 8 years ago

Maybe the PR #46 solve this issue

LogentriesCommunity / le_python

Incompatibilty with gunicorn. #3