Middleware being called twice for every request, help?

[Tyler Bettilyon]

Hello!

I recently switched my Django environment from using Apache to Gunicorn. After this switch we noticed that our middleware was being called twice for each request. To confirm my suspicion I wrote a new piece of middleware:

class TemporaryMiddleware(object):
    def process_request(self, request):
        if not hasattr(request, '_secret'):
            request._secret = uuid.uuid4()
            logging.info("set secret to {0}".format(request._secret))
        else:
            logging.info(request._secret)


    def process_response(self, request, response):
        logging.info("response {0}{1}".format(request._secret, response.status_code))
        return response

After registering my TemporaryMiddleware I headed back to the logs:
INFO 2014-03-19 09:32:23,397 middleware.py:26] set secret to bb89e0ab-a30b-42ce-800b-7129a3b323ae
INFO 2014-03-19 09:32:23,398 middleware.py:28] bb89e0ab-a30b-42ce-800b-7129a3b323ae
INFO 2014-03-19 09:32:23,841 middleware.py:32] response bb89e0ab-a30b-42ce-800b-7129a3b323ae200
INFO 2014-03-19 09:32:24,126 middleware.py:32] response bb89e0ab-a30b-42ce-800b-7129a3b323ae200

If the only change I make is to start the server using:
python manage.py runserver

Instead of:
python manage.py run_gunicorn

my logs say:
INFO 2014-03-19 09:48:25,325 middleware.py:26] set secret to 84b011f9-1689-4b2f-8202-01840c249937
INFO 2014-03-19 09:48:25,842 middleware.py:33] response 84b011f9-1689-4b2f-8202-01840c249937200

It seems to me that every request is being processed twice. This happens regardless of the number of threads or workers available, and when I run with more than 1 worker and/or more than one thread the process and thread id's for all four logging statements are the same. So I believe one thread is running through all of my middleware twice per request. 

Has anyone seem anything like this before, or have any idea what might be going on? I've only been Djangoing for ~6 months and sometimes configuration stuff still escapes me.

Thanks,
Tyler Bettilyon

[Nikolas Stevenson-Molnar]

Are you making the request from a browser? If so, your browser is probably making an extra request for the favicon. So if your middleware handles all requests (even ones that ultimately result in 404) then it'll be executed twice. It will look like it's twice for one request, but it's actually two separate requests.

_Nik

--
You received this message because you are subscribed to the Google Groups "Django users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to django-users...@googlegroups.com.
To post to this group, send email to django...@googlegroups.com.
Visit this group at http://groups.google.com/group/django-users.
To view this discussion on the web visit https://groups.google.com/d/msgid/django-users/684d2911-715e-4e6a-9ad9-ceda71607c22%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Tom Evans]

On Wed, Mar 19, 2014 at 5:50 PM, Nikolas Stevenson-Molnar
<nik.m...@consbio.org> wrote:
> Are you making the request from a browser? If so, your browser is probably
> making an extra request for the favicon.

Two requests that just happened to generate the same random uuid, and
skipped all other middleware processing apart from process_response?
Unlikely!

OP, you might want to repost, explicitly pointing out (in the subject)
that this only happens when you use run_gunicorn and never happens
when you use runserver.

Cheers

Tom

[Xavier Ordoquy]

Hi,

Just remove the Django debug toolbar.

It will call your middlewares to display the result.

Regards,

Xavier,

Linovia.

[Nikolas Stevenson-Molnar]

Ah yes. I missed/ignored the UUIDs entirely!

_Nik