Events are not sent with threaded transport using uWSGI with prefork

[antwan]

Hi,

When trying to send events to the logging server with the default (threaded) transport mode and uWSGI as application server, the events are not sent provided the request is handled by a children spawned process.

Example :

The server : uwsgi --http :8080 --module conf.wsgi --home venv --process 2 --enable-threads

The log :

*** Operational MODE: preforking ***
WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x26b9190 pid: 14124 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (pid: 14124, cores: 1)
spawned uWSGI worker 2 (pid: 14135, cores: 1)
[pid: 14124|app: 0|req: 1/1] 5.148.1.250 () {38 vars in 709 bytes} [Mon Mar 30 17:59:29 2015] GET /v1/crash/ => generated 227 bytes in 61 msecs (HTTP/1.1 500) 3 headers in 113 bytes (1 switches on core 0)
[pid: 14135|app: 0|req: 1/2] 5.148.1.250 () {40 vars in 740 bytes} [Mon Mar 30 17:59:40 2015] GET /v1/crash/ => generated 227 bytes in 51 msecs (HTTP/1.1 500) 3 headers in 113 bytes (1 switches on core 0)
[pid: 14124|app: 0|req: 2/3] 5.148.1.250 () {40 vars in 740 bytes} [Mon Mar 30 17:59:49 2015] GET /v1/crash/ => generated 227 bytes in 11 msecs (HTTP/1.1 500) 3 headers in 113 bytes (1 switches on core 0)
[pid: 14135|app: 0|req: 2/4] 5.148.1.250 () {38 vars in 710 bytes} [Mon Mar 30 18:04:07 2015] GET /v1/crash/ => generated 227 bytes in 13 msecs (HTTP/1.1 500) 3 headers in 113 bytes (1 switches on core 0)
[pid: 14124|app: 0|req: 3/5] 5.148.1.250 () {38 vars in 710 bytes} [Mon Mar 30 18:04:18 2015] GET /v1/crash/ => generated 227 bytes in 19 msecs (HTTP/1.1 500) 3 headers in 113 bytes (1 switches on core 0)

Only 3 messages are sent to the server (the one being handled by PID 14124).

When terminating uWSGI :

Sentry is attempting to send 2 pending error messages
Waiting up to 10 seconds
Press Ctrl-C to quit

Other example : uwsgi --http :8080 --module conf.wsgi --home venv --process 3 --threads 2

Log :

*** Operational MODE: preforking+threaded ***
WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x15781c0 pid: 14785 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (pid: 14785, cores: 2)
spawned uWSGI worker 2 (pid: 14797, cores: 2)
spawned uWSGI worker 3 (pid: 14798, cores: 2)

Same with --master (in this case nothing is send), or --emperor. Everything spawning processes prevent the messages from being sent. uWSGI v 2.0.10

This should be related to PR #583 though this does not fix the issue.

[xordoquy]

uWSGI is a bit different, see http://raven.readthedocs.org/en/latest/config/index.html#a-note-on-uwsgi

[dcramer]

@xordoquy we actually talked in IRC and it seems this is an additional problem (beyond the threaded notes)

[antwan]

Note after more tests, this behavior can be reproduced even with Python threads support disabled (i.e messages go through the first process only, but they go trough).

This means for some reason the threading is not effective at all with uWSGI...

Maybe a solution might be to create a specific transport layer for uWSGI using their low-level threading api.

[dcramer]

@Antwan86 we want to move away from all the custom transports as they're generally not needed. I'm sure this is just a case of the worker not correctly running after fork, but I haven't had a chance to look at it yet.

[mrkschan]

Hit similar issue but not sure if this's the same one.

My case is like this ... Django warnings RemovedInDjango19Warning can be sent to Sentry when uWSGI starts but all other log events afterwards are not sent. The queue size of the threaded HTTP transport keeps increasing for each new log events.

Environment.

• Django 1.8.4
• Python 2.7.6
• Raven 5.6.0
• uWSGI 2.0.11

Note: This problem did not occur when i was using Django 1.4.x 2 days ago.

[tuomas2]

I'm also affected, with Django 1.8.6. I also tested with Django 1.7, with which I could not reproduce it.

Tested with most raven 5.8.1 and uWSGI 2.0.11.2.

[tuomas2]

More info:

If in uWSGI configuration master process is disabled (master=false), and workers=1, then messages will get through. If more workers, it appears that only the messages that are sent from the first worker get through.

Looks like some thread locking issue that is trickered by Django 1.8 upgrade.

[tuomas2]

For the record, my 'workaround' solution for this was to implement redis based transport. https://gist.github.com/tuomas2/5f85df7dc90ea4c33f8b

[dalang]

I stuck in the same issue while I changed sentry logger level from ERROR to WARNING in django settings file. Now I can only get 504 gateway time-out in django response.

environment * django 1.9 * raven 5.31.0 * uwsgi 2.0.11

[luckydonald]

@xordoquy Linked documentation doesn't exist anymore.

[lovemyliwu]

@luckydonald https://github.com/getsentry/raven-python/blob/master/docs/advanced.rst#a-note-on-uwsgi

basically you need enable threads in uwsgi that's all.

cc @dalang

[luckydonald]

I got away with using the non threaded sender class:

from raven.transport import HTTPTransport
client = raven.Client(transport=HTTPTransport)

[vova-ukraine]

You can force set sync HTTPTransport module as default transport module by Djnago settings:

RAVEN_CONFIG = {
    'dsn': '...',
    'transport': 'raven.transport.http.HTTPTransport'
}