On Mon, Nov 21, 2011 at 3:07 AM, Graham Dumpleton
<[email protected]> wrote:
> On 20 November 2011 14:08, Rodrigo Campos <[email protected]> wrote:
>>
>> Also, it seems there is something wrong with the date/hour I didn't
>> yet look. It didn't happen so much time between the "Script timed out"
>> and the killing. It seems some messages are logged using one time and
>> some others using other timezone/something like that. Because I have
>> this in the logs, for example:
>
> The timezone difference will be because one log message comes from
> Apache child process and the other from the mod_wsgi daemon process.
> If Django is overriding timezone then what is displayed will be
> different to what Apache child processes show.

It's probably that, then. Thanks :-)

>
>> Anyone has any idea/tip on how can I further debug this ?
>>
>> I've seen there are commits in WSGI (not included in any release yet)
>> that add a blocked timeout and blocker request parameters
>
> Yep. The inactivity-timeout has been serving double duty. It was
> really intended for when the process is completely idle with no
> requests arriving or being handled. In place of a better solution at
> the time, also made it so that it would detect case where no requests
> arriving but there were existing requests and for the total of those
> active requests there was no input or output. So, worked as a poor
> failsafe for when the process as a whole hung because of all requests
> blocking for some reason.
>
> In mod_wsgi 4.0 those concepts are properly separated. The
> inactivity-timeout is only for case where process is completely idle,
> no active requests at all.

Is there any estimated date when mod_wsgi 4.0 will be released ?
Is it too risky to try to compile todays trunk and use it in
production (previous sevral days on testing) ? Are there any "blocker"
issue you are aware of ?

>
> The new options for the busy case are blocked-requests and
> blocked-timeout. By default the blocked restart is not enabled. It can
> be enabled by setting blocked-timeout in much the same was as
> inactivity-timeout option. When blocked-requests is not set, it
> defaults to what ever the number of threads is for the mod_wsgi daemon
> process.
>
> What happens is that when the blocked-timeout is defined, when the
> number of concurrent requests is equal to or exceeds blocked-requests,
> if there is no input or output for any requests for period set by
> blocked-timeout, then the process will be restarted.

Great, thanks!
That's why I asked for these parameters, I've read some similar
description on your post on stackoverflow and now saw commits on trunk
that seems to implement them. This is a great feature for us right
now, we are *just* needing it =)

>
> So, if blocked-requests isn't set and defaults to total threads, then
> when whole process effectively hangs, then it will restart.

Right, makes sense

> I need to think about how this all works some more and see whether I
> can better determine if individual requests are producing no input and
> output and so likely blocked. I may yet be able to come up with a
> slightly better way of handling this and cause a restart sooner as
> soon as no other active requests in addition to the blocked ones. That
> way will not have situation where in busy site will still end up
> reaching maximum number of threads being blocked before forced
> restart.
>
>> and an other
>> one to get some information of the processes/threads (which
>> information ?
>
> This is some experimental stuff that works in conjunction with New
> Relic agent to track number of concurrent requests and thread
> utilisation. It can be graphed in New Relic using custom views. I am
> not entirely happy with interface into mod_wsgi for this at this point
> and so will be changing how this works.
>
>> a call-trace perhaps ? :-)).
>
> I have just committed some changes that adds a feature where by if a
> restart is performed due to blocked requests then it will dump out
> what any active requests in the process are doing. You would therefore
> see in the Apache logs:

Great, thanks a lot!

>
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Daemon process
> busy inactivity timer expired, stopping process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Shutdown
> requested 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Dumping stack
> trace for active Python threads.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Thread
> 4320296960 executing file
> "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 8, in
> function
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): called from
> file "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 12,
> in application.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Thread
> 4320833536 executing file
> "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 8, in
> function
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): called from
> file "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 12,
> in application.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Thread
> 4321370112 executing file
> "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 8, in
> function
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): called from
> file "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 12,
> in application.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Thread
> 4313858048 executing file
> "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 8, in
> function
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): called from
> file "/Library/WebServer/Sites/hello-1/htdocs/environ.wsgi", line 12,
> in application.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 10 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 9 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 5 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 8 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 7 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 6 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 4 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 3 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 2 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:52 2011] [info] mod_wsgi (pid=12256): Exiting thread
> 1 in daemon process 'hello-1'.
> [Mon Nov 21 15:18:57 2011] [info] mod_wsgi (pid=12256): Aborting
> process 'hello-1'.
> [Mon Nov 21 15:18:57 2011] [error] [client 127.0.0.1] Premature end of
> script headers: environ.wsgi
> [Mon Nov 21 15:18:57 2011] [error] [client 127.0.0.1] Premature end of
> script headers: environ.wsgi
> [Mon Nov 21 15:18:57 2011] [error] [client 127.0.0.1] Premature end of
> script headers: environ.wsgi
> [Mon Nov 21 15:18:57 2011] [error] [client 127.0.0.1] Premature end of
> script headers: environ.wsgi
>
> It does require LogLevel in Apache to be set to 'info' though. There
> is only file name, line number and function name context. It isn't
> really feasible to give code line like normal Python tracebacks as
> this is reaching from underneath all interpreters and written in C
> code. It is happening on shutdown and also has to avoid doing stuff
> that might result in GIL being released and other code being run. So,
> has to be simple as possible. Should be sufficient though in helping
> to target trouble spot.

Sorry, I'm not sure I followed you here. The trace gives file name,
line number and function name context but the line number is not
feasible ? Or what is not feasible ? Sorry, I lost you :S

>
>> If I understand correctly
>> this could be *very* helpful to debug this problem. Also, if we could
>> have a trace where the blocked process where hanging it will be *very
>> very* useful :-D
>>
>> Is there some other configuration option that could help ? Do you know
>> when will be a new release that includes the "blocked request"
>> parameters ?
>
> Above is all I can think of right now in rush before have to go back
> home to no proper internet.

That's enough :-)






Thanks a lot!

Rodrigo

-- 
You received this message because you are subscribed to the Google Groups 
"modwsgi" group.
To post to this group, send email to [email protected].
To unsubscribe from this group, send email to 
[email protected].
For more options, visit this group at 
http://groups.google.com/group/modwsgi?hl=en.

Reply via email to