'Premature end of script headers' happens time to time
qrilka
I have read quite a lot of discussions about problems leading to
'PReamature end of script headers' line in apache log but I still can
not find a way to resolve it completely.
On avastep.ru we have a Django app (main functionality done with PIL).
Site works OK but from time to time I get a line in error log like:
---
[Wed Jan 06 21:15:16 2010] [error] [client 85.175.67.142] Premature
end of script headers: factory.wsgi, referer: http://www.avastep.ru/
---
and it appears that some of site users have problems.
I could not find any way to reproduce this problem otherwise than on
that working server.
httpd.conf for the site - http://dpaste.com/141757/
Software installed: CentOS release 5.2 (Final), Python 2.4.3, mod_wsgi
2.8 (from http://codepoint.net/attachments/mod_wsgi/)
Is there any way to diagnose what is wrong with server configuration
and how could it be fixed?
Many thanks in advance.
Best regards,
Kirill Zaborsky
Graham Dumpleton
Set:
LogLevel info
in Apache configuration.
If the messages coincides with mod_wsgi daemon mode process restarts,
it may be because there are active long running requests at time when
'maximum-requests=50000' option of WSGIDaemonProcess is triggered.
These may also be stuck requests.
This could occur because when that process recycling is triggered, it
will only wait so long, default 5 seconds, for any other active
requests handled by the process to complete. If they don't complete
the process is forcibly killed off. This killing off of the process
would result in Apache server child process proxying the request
seeing connection close and thus a premature end of the headers being
returned by mod_wsgi daemon process.
I realise the message is a bit confusing, but so happen to be using a
bit of existing Apache code normally used when dealing with CGI
scripts. Thus the message is actually same message as can get when CGI
scripts don't return headers even though is a WSGI script handled by
mod_wsgi.
So, do you have long running requests which would take a long time
before they generate the headers for the response?
Graham
qrilka
"processes=5 threads=1" but now receive even more errors and server is
almost unusable (a lot of 500 errors).
Best regards,
Kirill Zaborsky
On Jan 6, 9:34 pm, qrilka <qri...@gmail.com> wrote:
> Hello,
> I have read quite a lot of discussions about problems leading to
> 'PReamature end of script headers' line in apache log but I still can
> not find a way to resolve it completely.
> On avastep.ru we have a Django app (main functionality done with PIL).
> Site works OK but from time to time I get a line in error log like:
> ---
> [Wed Jan 06 21:15:16 2010] [error] [client 85.175.67.142] Premature
> end of script headers: factory.wsgi, referer:http://www.avastep.ru/
> ---
> and it appears that some of site users have problems.
> I could not find any way to reproduce this problem otherwise than on
> that working server.
>
> httpd.conf for the site -http://dpaste.com/141757/
> Software installed: CentOS release 5.2 (Final), Python 2.4.3, mod_wsgi
> 2.8 (fromhttp://codepoint.net/attachments/mod_wsgi/)
qrilka
meaningful.
I will try to get error log later to post it here (maybe I missed
something).
Best regards,
Kirill Zaborsky
On Jan 7, 1:20 pm, Graham Dumpleton <graham.dumple...@gmail.com>
wrote:
> 2010/1/7 qrilka <qri...@gmail.com>:
>
>
>
> > Hello,
> > I have read quite a lot of discussions about problems leading to
> > 'PReamature end of script headers' line in apache log but I still can
> > not find a way to resolve it completely.
> > On avastep.ru we have a Django app (main functionality done with PIL).
> > Site works OK but from time to time I get a line in error log like:
> > ---
> > [Wed Jan 06 21:15:16 2010] [error] [client 85.175.67.142] Premature
> > end of script headers: factory.wsgi, referer:http://www.avastep.ru/
> > ---
> > and it appears that some of site users have problems.
> > I could not find any way to reproduce this problem otherwise than on
> > that working server.
>
> > httpd.conf for the site -http://dpaste.com/141757/
> > Software installed: CentOS release 5.2 (Final), Python 2.4.3, mod_wsgi
> > 2.8 (fromhttp://codepoint.net/attachments/mod_wsgi/)
Graham Dumpleton
> Actually I run prefork Apache so I changed "threads=25" to
> "processes=5 threads=1" but now receive even more errors and server is
> almost unusable (a lot of 500 errors).
From where, Apache, mod_wsgi or Django?
I am assuming not the same premature end of script headers issue but
something else.
More specific information from error logs for these my be helpful
although sounds like a different issue.
Graham
> Best regards,
> Kirill Zaborsky
>
> On Jan 6, 9:34 pm, qrilka <qri...@gmail.com> wrote:
>> Hello,
>> I have read quite a lot of discussions about problems leading to
>> 'PReamature end of script headers' line in apache log but I still can
>> not find a way to resolve it completely.
>> On avastep.ru we have a Django app (main functionality done with PIL).
>> Site works OK but from time to time I get a line in error log like:
>> ---
>> [Wed Jan 06 21:15:16 2010] [error] [client 85.175.67.142] Premature
>> end of script headers: factory.wsgi, referer:http://www.avastep.ru/
>> ---
>> and it appears that some of site users have problems.
>> I could not find any way to reproduce this problem otherwise than on
>> that working server.
>>
>> httpd.conf for the site -http://dpaste.com/141757/
>> Software installed: CentOS release 5.2 (Final), Python 2.4.3, mod_wsgi
>> 2.8 (fromhttp://codepoint.net/attachments/mod_wsgi/)
>>
>> Is there any way to diagnose what is wrong with server configuration
>> and how could it be fixed?
>> Many thanks in advance.
>>
>> Best regards,
>> Kirill Zaborsky
>
> --
> You received this message because you are subscribed to the Google Groups "modwsgi" group.
> To post to this group, send email to mod...@googlegroups.com.
> To unsubscribe from this group, send email to modwsgi+u...@googlegroups.com.
> For more options, visit this group at http://groups.google.com/group/modwsgi?hl=en.
>
>
>
>
Graham Dumpleton
> I have tried to set logging to info bu could not find anything
> meaningful.
> I will try to get error log later to post it here (maybe I missed
> something).
I am interested in the proximity of any messages indicating that
daemon mode process are being restarted.
If running VirtualHost specific error logs, you may also have to look
in main Apache error log, specially if using mod_wsgi 2.8 and not
mod_wsgi 3.1.
Graham
qrilka
------------------------
[Thu Jan 07 21:09:49 2010] [info] mod_wsgi (pid=12366): Maximum
requests reached 'av_factory'.
[Thu Jan 07 21:09:49 2010] [info] mod_wsgi (pid=12366): Shutdown
requested 'av_factory'.
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=12366): Aborting
process 'av_factory'.
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=28423): Attach
interpreter ''.
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=28423): Enable monitor
thread in process 'av_factory'.
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=28423): Enable
deadlock thread in process 'av_factory'.
[Thu Jan 07 21:09:54 2010] [info] [client 188.113.58.162] mod_wsgi
(pid=28423, process='av_factory', application=''): Loading WSGI script
'/var/vhosts/avaste
p.ru/avatar_factory/apache/factory.wsgi'.
[Thu Jan 07 21:10:05 2010] [error] [client 94.181.240.3] (104)
Соединение сброшено другой стороной: mod_wsgi (pid=27832): Unable to
get bucket brigade for req
uest., referer: http://www.avastep.ru/
[Thu Jan 07 21:10:06 2010] [error] [client 94.181.240.3] mod_wsgi
(pid=28423): Exception occurred processing WSGI script '/var/vhosts/
avastep.ru/avatar_facto
ry/apache/factory.wsgi'.
[Thu Jan 07 21:10:06 2010] [error] [client 94.181.240.3] IOError:
client connection closed
[Thu Jan 07 21:10:08 2010] [error] [client 92.39.71.47] (70007)The
timeout specified has expired: mod_wsgi (pid=25597): Unable to get
bucket brigade for requ
est., referer: http://www.avastep.ru/
[Thu Jan 07 21:10:16 2010] [error] [client 91.76.128.137] (70007)The
timeout specified has expired: mod_wsgi (pid=25627): Unable to get
bucket brigade for re
quest., referer: http://www.avastep.ru/
[Thu Jan 07 21:10:24 2010] [error] [client 109.187.113.64] Premature[Thu Jan 07 21:11:04 2010] [error] [client 94.248.42.230] Premature
end of script headers: factory.wsgi, referer: http://avastep.ru/
------------------------
Main Apache error log at the same time:
------------------------
[Thu Jan 07 21:09:49 2010] [info] mod_wsgi (pid=26071): Cleanup
interpreter ''.
[Thu Jan 07 21:09:49 2010] [info] mod_wsgi (pid=26071): Terminating
Python.
[Thu Jan 07 21:09:50 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:09:50 2010] [info] mod_wsgi (pid=28083): Cleanup
interpreter ''.
[Thu Jan 07 21:09:50 2010] [info] mod_wsgi (pid=28083): Terminating
Python.
[Thu Jan 07 21:09:51 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:09:51 2010] [info] mod_wsgi (pid=28066): Cleanup
interpreter ''.
[Thu Jan 07 21:09:51 2010] [info] mod_wsgi (pid=28066): Terminating
Python.
[Thu Jan 07 21:09:51 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:09:52 2010] [info] [client 89.222.228.40] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:09:52 2010] [info] [client 89.222.228.40] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:09:52 2010] [info] [client 89.222.228.40] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:09:52 2010] [info] [client 89.222.228.40] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:09:52 2010] [info] mod_wsgi (pid=26755): Cleanup
interpreter ''.
[Thu Jan 07 21:09:52 2010] [info] mod_wsgi (pid=26755): Terminating
Python.
[Thu Jan 07 21:09:53 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:09:53 2010] [info] mod_wsgi (pid=26523): Cleanup
interpreter ''.
[Thu Jan 07 21:09:53 2010] [info] mod_wsgi (pid=26523): Terminating
Python.
[Thu Jan 07 21:09:53 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=12366): Process
'av_factory' has died, restarting.
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=28423): Starting
process 'av_factory' with uid=504, gid=48 and threads=15.
[Thu Jan 07 21:09:54 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=28110): Cleanup
interpreter ''.
[Thu Jan 07 21:09:55 2010] [info] mod_wsgi (pid=28110): Terminating
Python.
[Thu Jan 07 21:09:55 2010] [info] [client 83.149.10.135] (104)
Соединение сброшено другой стороной: core_output_filter: writing data
to the network
[Thu Jan 07 21:09:57 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:09:57 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:09:58 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:09:58 2010] [info] mod_wsgi (pid=28498): Attach
interpreter ''.
[Thu Jan 07 21:09:59 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:09:59 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:09:59 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:01 2010] [info] [client 78.36.103.252] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:02 2010] [info] mod_wsgi (pid=28103): Cleanup
interpreter ''.
[Thu Jan 07 21:10:02 2010] [info] mod_wsgi (pid=28103): Terminating
Python.
[Thu Jan 07 21:10:02 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:04 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:05 2010] [info] mod_wsgi (pid=28564): Attach
interpreter ''.
[Thu Jan 07 21:10:05 2010] [info] [client 94.181.240.3] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:05 2010] [info] [client 94.181.240.3] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:06 2010] [info] [client 188.187.12.88] (70007)The
timeout specified has expired: core_output_filter: writing data to the
network
[Thu Jan 07 21:10:06 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:07 2010] [info] [client 79.165.120.17] (70007)The
timeout specified has expired: core_output_filter: writing data to the
network
[Thu Jan 07 21:10:07 2010] [info] mod_wsgi (pid=28579): Attach
interpreter ''.
[Thu Jan 07 21:10:08 2010] [info] [client 85.249.160.62] (70014)End of
file found: core_output_filter: writing data to the network
[Thu Jan 07 21:10:10 2010] [info] mod_wsgi (pid=28086): Cleanup
interpreter ''.
[Thu Jan 07 21:10:10 2010] [info] mod_wsgi (pid=28086): Terminating
Python.
[Thu Jan 07 21:10:11 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:11 2010] [info] mod_wsgi (pid=27794): Cleanup
interpreter ''.
[Thu Jan 07 21:10:11 2010] [info] mod_wsgi (pid=27794): Terminating
Python.
[Thu Jan 07 21:10:12 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:12 2010] [info] mod_wsgi (pid=26757): Cleanup
interpreter ''.
[Thu Jan 07 21:10:12 2010] [info] mod_wsgi (pid=26757): Terminating
Python.
[Thu Jan 07 21:10:13 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:13 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:13 2010] [info] mod_wsgi (pid=27968): Cleanup
interpreter ''.
[Thu Jan 07 21:10:13 2010] [info] mod_wsgi (pid=27968): Terminating
Python.
[Thu Jan 07 21:10:14 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:14 2010] [info] [client 109.184.199.22] (104)
Соединение сброшено другой стороной: core_output_filter: writing data
to the network
[Thu Jan 07 21:10:14 2010] [info] mod_wsgi (pid=27814): Cleanup
interpreter ''.
[Thu Jan 07 21:10:14 2010] [info] mod_wsgi (pid=27814): Terminating
Python.
[Thu Jan 07 21:10:14 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:14 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:15 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:15 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:15 2010] [info] mod_wsgi (pid=26703): Cleanup
interpreter ''.
[Thu Jan 07 21:10:15 2010] [info] mod_wsgi (pid=26703): Terminating
Python.
[Thu Jan 07 21:10:15 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:16 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:16 2010] [info] mod_wsgi (pid=27458): Cleanup
interpreter ''.
[Thu Jan 07 21:10:16 2010] [info] mod_wsgi (pid=27458): Terminating
Python.
[Thu Jan 07 21:10:16 2010] [info] [client 109.184.199.22] (104)
Соединение сброшено другой стороной: core_output_filter: writing data
to the network
[Thu Jan 07 21:10:17 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:17 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:18 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:18 2010] [info] mod_wsgi (pid=28678): Attach
interpreter ''.
[Thu Jan 07 21:10:19 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:21 2010] [info] mod_wsgi (pid=28705): Attach
interpreter ''.
[Thu Jan 07 21:10:22 2010] [info] mod_wsgi (pid=28710): Attach
interpreter ''.
[Thu Jan 07 21:10:22 2010] [info] mod_wsgi (pid=28711): Attach
interpreter ''.
[Thu Jan 07 21:10:22 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:23 2010] [info] mod_wsgi (pid=28725): Attach
interpreter ''.
[Thu Jan 07 21:10:23 2010] [info] mod_wsgi (pid=28726): Attach
interpreter ''.
[Thu Jan 07 21:10:23 2010] [info] mod_wsgi (pid=28727): Attach
interpreter ''.
[Thu Jan 07 21:10:23 2010] [info] mod_wsgi (pid=28728): Attach
interpreter ''.
[Thu Jan 07 21:10:23 2010] [info] [client 217.66.22.68] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:23 2010] [info] [client 217.66.22.68] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:24 2010] [info] [client 217.66.22.68] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:26 2010] [info] [client 94.241.48.58] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:26 2010] [info] [client 94.241.48.58] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:26 2010] [info] [client 94.241.48.58] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:27 2010] [info] [client 94.241.48.58] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:27 2010] [info] [client 94.241.48.58] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:27 2010] [info] mod_wsgi (pid=27512): Cleanup
interpreter ''.
[Thu Jan 07 21:10:27 2010] [info] mod_wsgi (pid=27512): Terminating
Python.
[Thu Jan 07 21:10:28 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:30 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:30 2010] [info] mod_wsgi (pid=28105): Cleanup
interpreter ''.
[Thu Jan 07 21:10:30 2010] [info] mod_wsgi (pid=28105): Terminating
Python.
[Thu Jan 07 21:10:31 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:31 2010] [info] [client 92.245.50.110] (70007)The
timeout specified has expired: core_output_filter: writing data to the
network
[Thu Jan 07 21:10:31 2010] [info] [client 92.245.50.110] (70007)The
timeout specified has expired: core_output_filter: writing data to the
network
[Thu Jan 07 21:10:31 2010] [info] mod_wsgi (pid=28054): Cleanup
interpreter ''.
[Thu Jan 07 21:10:31 2010] [info] mod_wsgi (pid=28054): Terminating
Python.
[Thu Jan 07 21:10:32 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:32 2010] [info] mod_wsgi (pid=25627): Cleanup
interpreter ''.
[Thu Jan 07 21:10:32 2010] [info] mod_wsgi (pid=25627): Terminating
Python.
[Thu Jan 07 21:10:33 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:33 2010] [info] mod_wsgi (pid=28678): Cleanup
interpreter ''.
[Thu Jan 07 21:10:33 2010] [info] mod_wsgi (pid=28678): Terminating
Python.
[Thu Jan 07 21:10:34 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:34 2010] [info] mod_wsgi (pid=27844): Cleanup
interpreter ''.
[Thu Jan 07 21:10:34 2010] [info] mod_wsgi (pid=27844): Terminating
Python.
[Thu Jan 07 21:10:35 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:35 2010] [info] mod_wsgi (pid=28818): Attach
interpreter ''.
[Thu Jan 07 21:10:39 2010] [info] mod_wsgi (pid=28099): Cleanup
interpreter ''.
[Thu Jan 07 21:10:39 2010] [info] mod_wsgi (pid=28099): Terminating
Python.
[Thu Jan 07 21:10:40 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:40 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:41 2010] [info] mod_wsgi (pid=28097): Cleanup
interpreter ''.
[Thu Jan 07 21:10:41 2010] [info] mod_wsgi (pid=28097): Terminating
Python.
[Thu Jan 07 21:10:42 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:42 2010] [info] mod_wsgi (pid=28078): Cleanup
interpreter ''.
[Thu Jan 07 21:10:42 2010] [info] mod_wsgi (pid=28078): Terminating
Python.
[Thu Jan 07 21:10:43 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:43 2010] [info] mod_wsgi (pid=27996): Cleanup
interpreter ''.
[Thu Jan 07 21:10:43 2010] [info] mod_wsgi (pid=27996): Terminating
Python.
[Thu Jan 07 21:10:44 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:45 2010] [info] mod_wsgi (pid=28108): Cleanup
interpreter ''.
[Thu Jan 07 21:10:45 2010] [info] mod_wsgi (pid=28108): Terminating
Python.
[Thu Jan 07 21:10:45 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:45 2010] [info] mod_wsgi (pid=26088): Cleanup
interpreter ''.
[Thu Jan 07 21:10:45 2010] [info] mod_wsgi (pid=26088): Terminating
Python.
[Thu Jan 07 21:10:46 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:46 2010] [info] mod_wsgi (pid=27979): Cleanup
interpreter ''.
[Thu Jan 07 21:10:46 2010] [info] mod_wsgi (pid=27979): Terminating
Python.
[Thu Jan 07 21:10:47 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:49 2010] [info] mod_wsgi (pid=28935): Attach
interpreter ''.
[Thu Jan 07 21:10:50 2010] [info] mod_wsgi (pid=28947): Attach
interpreter ''.
[Thu Jan 07 21:10:50 2010] [info] mod_wsgi (pid=28948): Attach
interpreter ''.
[Thu Jan 07 21:10:51 2010] [info] mod_wsgi (pid=28498): Cleanup
interpreter ''.
[Thu Jan 07 21:10:51 2010] [info] mod_wsgi (pid=28498): Terminating
Python.
[Thu Jan 07 21:10:52 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:52 2010] [info] mod_wsgi (pid=27832): Cleanup
interpreter ''.
[Thu Jan 07 21:10:52 2010] [info] mod_wsgi (pid=27832): Terminating
Python.
[Thu Jan 07 21:10:53 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:55 2010] [info] mod_wsgi (pid=22658): Cleanup
interpreter ''.
[Thu Jan 07 21:10:55 2010] [info] mod_wsgi (pid=22658): Terminating
Python.
[Thu Jan 07 21:10:56 2010] [info] [client ::1] (32)Broken pipe:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:56 2010] [info] [client 109.184.199.22] (104)
Connection reset by peer: core_output_filter: writing data to the
network
[Thu Jan 07 21:10:56 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:10:56 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:10:57 2010] [info] mod_wsgi (pid=27830): Cleanup
interpreter ''.
[Thu Jan 07 21:10:57 2010] [info] mod_wsgi (pid=27830): Terminating
Python.
[Thu Jan 07 21:10:58 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:10:58 2010] [info] mod_wsgi (pid=29013): Attach
interpreter ''.
[Thu Jan 07 21:10:59 2010] [info] [client 109.184.199.22] (70007)The
timeout specified has expired: core_output_filter: writing data to the
network
[Thu Jan 07 21:11:00 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:11:00 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:11:01 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:11:01 2010] [info] mod_wsgi (pid=28067): Cleanup
interpreter ''.
[Thu Jan 07 21:11:01 2010] [info] mod_wsgi (pid=28067): Terminating
Python.
[Thu Jan 07 21:11:02 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:11:02 2010] [info] mod_wsgi (pid=26744): Cleanup
interpreter ''.
[Thu Jan 07 21:11:02 2010] [info] mod_wsgi (pid=26744): Terminating
Python.
[Thu Jan 07 21:11:03 2010] [info] [client ::1] (32)Обрыв канала:
core_output_filter: writing data to the network
[Thu Jan 07 21:11:04 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:11:04 2010] [info] mod_wsgi (pid=29067): Attach
interpreter ''.
[Thu Jan 07 21:11:04 2010] [info] [client 109.184.199.22] (32)Broken
pipe: core_output_filter: writing data to the network
[Thu Jan 07 21:11:04 2010] [info] [client 109.184.199.22] (32)Обрыв
канала: core_output_filter: writing data to the network
[Thu Jan 07 21:11:08 2010] [info] mod_wsgi (pid=28726): Cleanup
interpreter ''.
[Thu Jan 07 21:11:08 2010] [info] mod_wsgi (pid=28726): Terminating
Python.
-------------------------------
Обрыв канала == Broken pipe (but in Russian)
I do not see any other problems here except broken pipes.
On Jan 7, 2:59 pm, Graham Dumpleton <graham.dumple...@gmail.com>
qrilka
after some timeout I get Internal Server Error from Apache (but
sometimes I get normal page but with some delay). The logs I posted
some minutes ago are done for cofiguration with
----
WSGIDaemonProcess av_factory user=avfactory threads=15 maximum-
requests=10000 display-name=AVASTEP.RU_WSGI
----
Best regards,
Kirill Zaborsky
On Jan 7, 2:57 pm, Graham Dumpleton <graham.dumple...@gmail.com>
wrote:
qrilka
uses non-reentrant MYSQL library and MySQLdb uses reentrant version.
So I have compiled MySQLdb from the source with no multithreading
support (as I did not find how to make PHP MySQL reentrant)
But the server exhibits the same behaviour.
Now I'm stuck and have no further ideas where the problem can exist.
I will be thankful for any thoughts about this situation.
Best regards,
Kirill Zaborsky.
Graham Dumpleton
> From VirtualHost specific log:
> ------------------------
> [Thu Jan 07 21:09:49 2010] [info] mod_wsgi (pid=12366): Maximum
> requests reached 'av_factory'.
> [Thu Jan 07 21:09:49 2010] [info] mod_wsgi (pid=12366): Shutdown
> requested 'av_factory'.
> [Thu Jan 07 21:09:54 2010] [info] mod_wsgi (pid=12366): Aborting
> process 'av_factory'.
This line indicates that what I described previously is occurring and
is likely the cause.
That is, when reaching maximum-requests, there are long running
requests or stuck requests that don't complete within the default 5
second window for shutting down a daemon process.
When that occurs, even though still running the process is forcibly
exited, even without shutting down Python interpreter properly. As a
result, the Apache server child process which is proxying that
specific request to the mod_wsgi daemon mode process sees the
connection to daemon process abruptly cut off and as such you may see
errors about premature end of script headers or the various filter
errors or broken pipe messages depending on where a request was up to.
Do you have any idea about whether you legitimately have requests that
take longer than 5 seconds to process?
For what reason are you using maximum-requests in the first place? If
you don't have to use that option for some reason, the issue should be
avoided.
Graham
qrilka
Actually application is very simple and the only problem could be with
some operations on large images.
But I do not see how that could lead to some operations taking more
than 1 second.
I though that using maximum-requests could prevent possible memory
leaks and exessive memory consumption.
Isn't it a right supposition?
And also if I understand it right I will get the same errors on
application update when my WSGI application will be restarted.
Do you have any thoughts how could I find any misbehaving long-running
process with a stacktrace?
Best regards,
Kirill Zaborsky
On Jan 8, 1:06 am, Graham Dumpleton <graham.dumple...@gmail.com>
wrote:
Graham Dumpleton
> OK, I'll investigate how that could be solved.
> Actually application is very simple and the only problem could be with
> some operations on large images.
> But I do not see how that could lead to some operations taking more
> than 1 second.
That time of 5 seconds isn't just for processing of the image but also
inclusive of the time it takes to upload the image to the application
if what you are doing first involves an upload.
Thus, if dealing with large images or slow HTTP clients and clients
are talking direct to Apache, then you may well exceed that time.
What you can do to partly isolate yourself from problem of slow HTTP
clients is to put nginx proxy in front of Apache. At least for files
up to some default, nginx will buffer the upload before actually
triggering the proxy to the Apache back end. This means that request
only passed onto Apache when data is available and so Apache can do
its job quickly and not be tied up with dealing with slow HTTP
request. Thus less risk of request being interrupted if process does
indeed fall within that 5 seconds. Only passing on request when
request data available, also means you will get better utilisation
from Apache processes/threads and can configure it for less, thus
reducing its memory overhead.
Right now I can't find the part of the nginx documentation that talks
about request buffering. The proxy documentation tends only to talk
about response buffering as far as configuration parameters.
> I though that using maximum-requests could prevent possible memory
> leaks and exessive memory consumption.
> Isn't it a right supposition?
It can, but as described can cause conflict with long running
uploads/requests if they are greater than default shutdown timeout of
5 seconds. You can adjust the shutdown timeout using shutdown-timeout
option to WSGIDaemonProcess, but make it too long and you risk
perceived delays by user if all daemon mode processes in group restart
about the same time.
> And also if I understand it right I will get the same errors on
> application update when my WSGI application will be restarted.
Yes, the shutdown timeout comes into play on any self restart of
mod_wsgi daemon processes.
The only time that shutdown timeout doesn't apply is when you do a
full Apache 'restart' or 'graceful'. In that case Apache itself
applies a 3 second timeout and will forcibly kill the mod_wsgi daemon
mode processes after that. Can't override that specific Apache
timeout.
> Do you have any thoughts how could I find any misbehaving long-running
> process with a stacktrace?
One could use WSGI wrappers around your application object to add a
request timer, but would first contemplate on whether it is the upload
time for file rather than processing time.
Graham
qrilka
It was quite clear before that I need to spend more time on proper
server configuration (e.g. Apache now isn't quite tuned at least I
need to separate python from PHP). I will look into you proposal on
using nginx for proxying long-running requests.
BTW I removed maximum-requests but still see 'Premature end of script
headers' messages in error log.
What could be a reason for that?
Are there any other restarts for mod_wsgi except changed wsgi file and
maximum-requests option?
Many thanks for you help.
Best regards,
Kirill Zaborsky
On Jan 11, 3:23 am, Graham Dumpleton <graham.dumple...@gmail.com>
Graham Dumpleton
> Thanks for your reply, Graham.
> It was quite clear before that I need to spend more time on proper
> server configuration (e.g. Apache now isn't quite tuned at least I
> need to separate python from PHP). I will look into you proposal on
> using nginx for proxying long-running requests.
> BTW I removed maximum-requests but still see 'Premature end of script
> headers' messages in error log.
> What could be a reason for that?
> Are there any other restarts for mod_wsgi except changed wsgi file and
> maximum-requests option?
Could also occur if someone is doing an:
apachectl graceful
Ie., Apache graceful restart.
Can occur here because Apache will allow its own server child process
to keep running until active requests complete, but due to way APR
library handles the other processes such as mod_wsgi daemon processes,
it will kill them off regardless after 3 seconds. Thus, mod_wsgi
daemon process goes away and the Apache server child process proxying
request to the daemon process will then see connection close and get
that error message.
Presumably an Apache graceful shutdown could cause something similar.
The question is therefore if anyone is doing graceful restarts on
Apache at same time as you still see the message.
The only other times that error message could arise is if the mod_wsgi
daemon process crashed, or if someone has sent an explicit signal to
the mod_wsgi daemon process to make it shutdown.
Graham
qrilka
errors.
Today I'll try to setup nginx to see if it will help.
Best regards,
Kirill Zaborsky
On Jan 12, 1:39 am, Graham Dumpleton <graham.dumple...@gmail.com>
Graham Dumpleton
> Nobody else is doing anything with Apache but still I see the same
> errors.
> Today I'll try to setup nginx to see if it will help.
The message 'Premature end of script headers' also gets generated by
broken CGI scripts. So, you need to look quite closely at error logs
and ensure that they are in fact linked to a WSGI request.
qrilka
Just some PHP sites and Django.
And the message appears in Django virtual host log.
Best regards,
Kirill Zaborsky
On Jan 13, 1:33 am, Graham Dumpleton <graham.dumple...@gmail.com>
Graham Dumpleton
> There is no CGI scripts on that server.
> Just some PHP sites and Django.
> And the message appears in Django virtual host log.
Be aware that if this is being caused by a process crash, then the
Segmentation Fault message will appear in the main Apache error log
and not in the virtual host specific error log as is Apache parent
monitoring process which is monitoring the fact the process died and
it isn't linked to a specific virtual host.
So, ensure you are paying attention to any error messages in the main
Apache error log at the same time, including those which aren't
specifically tagged as coming from mod_wsgi. If you find anything of
relevance, then let me know.
qrilka
'Premature end' message).
Nginx upload module [1] requires some extra work and testing so it is
not on the production server yet.
I will let know if there will be any new details on this issue.
BTW it seems to be quite unlikely that I have some 'special' web
application which requires something like a voodoo magic and I don't
find any reports about such problems in the internet. It appears to me
to be some kind of server misconfiguration but I don't see any new
places where that misconfiguration could be.
[1] http://www.grid.net.ru/nginx/upload.en.html
Thanks once again.
Best regards,
Kirill Zaborsky
On Jan 13, 2:49 am, Graham Dumpleton <graham.dumple...@gmail.com>
> ...
>
> read more »
Graham Dumpleton
> No, I don't see anything like that (at least at the time of the latest
> 'Premature end' message).
> Nginx upload module [1] requires some extra work and testing so it is
> not on the production server yet.
FWIW, the benefits of using nginx in front to isolate Apache from slow
clients doesn't require that module. What I was talking about is
simply an aspect of how the standard nginx mod_proxy implementation
works.
Graham
qrilka
Did I miss something?
Anyways looks like we will try that module as it seem to work OK (but
some hours later)
Best regards,
Kirill Zaborsky
On Jan 13, 1:00 pm, Graham Dumpleton <graham.dumple...@gmail.com>
> ...
>
> read more »
Graham Dumpleton
> I could not find anything about uploads proxying in nginx docs.
> Did I miss something?
The mod_proxy module doesn't distinguish types of requests, any HTTP
request can have a body content and all mod_proxy does is pass that
data through to the backend as is for the original web application to
process. The module you are talking about actually tries to interpret
the data and splits it into files as I understand it. The web
application would then need to be modified somewhat to be able to pick
up special headers about where uploaded files were placed. As such,
that module will be incompatible with an existing Python web
frameworks file upload mechanisms.
Graham
qrilka
(Actually I forgot to update code to use upload module and it appeared
to be unnecessary :) )
Thanks for you help, Graham!
Best regards,
Kirill Zaborsky
On Jan 14, 12:50 am, Graham Dumpleton <graham.dumple...@gmail.com>
> ...
>
> read more »