httpd-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Daniel <dferra...@gmail.com>
Subject Re: [users@httpd] Random Internal Server Error 500 after apache and system update
Date Sun, 02 Oct 2016 09:07:58 GMT
I really see nothing in that strace output that tells anything is crashing.



2016-10-02 10:44 GMT+02:00 Fabio F.Gervasi <fabio.gervasi70@gmail.com>:

> Hi James,
>
> I do not have the skills to be able to work well in "depth" to the problem
> as you (rightly) suggest. What I know is that this problem started from the
> last system update (apache / php / mariadb, ...) from 23 September.
>
> The only log info is: /var/log/httpd/error_log, at "crash time": [Fri Sep
> 30 19:09:03.897325 2016] [mpm_event:trace4] [pid 30339:tid 139796798162688]
> event.c(930): socket reached timeout in lingering-close state
>
> and I don't know if strace (the results of which I have just quoted) is
> useful..
>
> Should I wait for further apache / php updates?
>
>
>
> *Fabio F. Gervasi*
> Engineering Consultant
>
>
> *Web             www.centrometeo.com <http://www.centrometeo.com/>*
> *g+                 plus.google.com/centrometeo
> <https://plus.google.com/105294368204645075621>*
>
> *Twitter        twitter.com/centrometeo <http://twitter.com/centrometeo>*
> *Facebook    facebook.com/centrometeo
> <http://www.facebook.com/centrometeo>*
>
>
>
>
>
>
>
>
>
> 2016-10-02 10:34 GMT+02:00 Dr James Smith <js5@sanger.ac.uk>:
>
>> Things you can do are trying to track down if there is any pattern - are
>> these first request on a child, "nth" request on  child etc... we add
>> additional variables to access logs which include things such as
>> PID/request no in PID, memory usage before and after etc. This allows us
>> sometimes to see patterns in errors which aren't normally easy to see..
>> Saying that it may not help you here...
>>
>> Another thing you can do with ab is check to see if it is OK under lower
>> load?
>>
>> Finally I find "siege" better than "ab" when it comes to testing as it is
>> more configurable - you can send it a list of URLs - run test for
>> "n-seconds" rather than "n-requests" which is more useful if you don't know
>> how long things take to return!
>>
>> James
>>
>>
>> On 02/10/2016 09:02, Daniel wrote:
>>
>> I would bet on your method of parsing php and the scripts being ran, in
>> any case to be sure:
>>
>> Try the strace approach:
>> strace -o /tmp/outputfile -s 5000 httpd -X or strace -ff -F -s200 -o
>> /tmp/strace.out -p PID
>>
>> to try to find out what's really going on.
>>
>> 2016-09-30 20:19 GMT+02:00 Fabio F.Gervasi <fabio.gervasi70@gmail.com>:
>>
>>> Hi!
>>>
>>> I have additional information:
>>>
>>> /var/log/httpd/error_log, at "crash time": [Fri Sep 30 19:09:03.897325
>>> 2016] [mpm_event:trace4] [pid 30339:tid 139796798162688] event.c(930):
>>> socket reached timeout in lingering-close state
>>>
>>> What do you think?
>>>
>>>
>>>
>>> 2016-09-30 14:47 GMT+02:00 Fabio F.Gervasi <fabio.gervasi70@gmail.com>:
>>>
>>>> Hi!
>>>>
>>>> Thank you for your reply. I tried the following tests.
>>>>
>>>> *1) Using a little text file:*
>>>> *# ab -k -c 100 -n 2000 localhost/test.txt*
>>>> This is ApacheBench, Version 2.3 <$Revision: 1748469 $>
>>>> Copyright 1996 Adam Twiss, Zeus Technology Ltd,
>>>> http://www.zeustech.net/
>>>> Licensed to The Apache Software Foundation, http://www.apache.org/
>>>>
>>>> Benchmarking localhost (be patient)
>>>> Completed 200 requests
>>>> Completed 400 requests
>>>> Completed 600 requests
>>>> Completed 800 requests
>>>> Completed 1000 requests
>>>> Completed 1200 requests
>>>> Completed 1400 requests
>>>> Completed 1600 requests
>>>> Completed 1800 requests
>>>> Completed 2000 requests
>>>> Finished 2000 requests
>>>>
>>>>
>>>> Server Software:        Apache/2.4.23
>>>> Server Hostname:        localhost
>>>> Server Port:            80
>>>>
>>>> Document Path:          /test.txt
>>>> Document Length:        52 bytes
>>>>
>>>> Concurrency Level:      100
>>>> Time taken for tests:   2.521 seconds
>>>> Complete requests:      2000
>>>> *Failed requests:        16*
>>>>    (Connect: 0, Receive: 0, Length: 16, Exceptions: 0)
>>>> Keep-Alive requests:    1984
>>>> Total transferred:      950336 bytes
>>>> HTML transferred:       103168 bytes
>>>> Requests per second:    793.45 [#/sec] (mean)
>>>> Time per request:       126.032 [ms] (mean)
>>>> Time per request:       1.260 [ms] (mean, across all concurrent
>>>> requests)
>>>> Transfer rate:          368.18 [Kbytes/sec] received
>>>>
>>>> Connection Times (ms)
>>>>               min  mean[+/-sd] median   max
>>>> Connect:        0    1   3.8      0      21
>>>> Processing:     1  123 126.5     83     772
>>>> Waiting:        0  123 126.7     83     772
>>>> Total:          1  124 126.6     85     772
>>>>
>>>> Percentage of the requests served within a certain time (ms)
>>>>   50%     85
>>>>   66%    154
>>>>   75%    201
>>>>   80%    229
>>>>   90%    303
>>>>   95%    373
>>>>   98%    452
>>>>   99%    547
>>>>  100%    772 (longest request)
>>>>
>>>> *I obtain 16 failed requests, but if I run more again I obtain a
>>>> different number.*
>>>>
>>>> *2) Using a big gif file:*
>>>> *# ab -k -c 100 -n 2000 localhost/it-vis-animation.gif*
>>>> This is ApacheBench, Version 2.3 <$Revision: 1748469 $>
>>>> Copyright 1996 Adam Twiss, Zeus Technology Ltd,
>>>> http://www.zeustech.net/
>>>> Licensed to The Apache Software Foundation, http://www.apache.org/
>>>>
>>>> Benchmarking localhost (be patient)
>>>> Completed 200 requests
>>>> Completed 400 requests
>>>> Completed 600 requests
>>>> Completed 800 requests
>>>> Completed 1000 requests
>>>> Completed 1200 requests
>>>> Completed 1400 requests
>>>> Completed 1600 requests
>>>> Completed 1800 requests
>>>> Completed 2000 requests
>>>> Finished 2000 requests
>>>>
>>>>
>>>> Server Software:        Apache/2.4.23
>>>> Server Hostname:        localhost
>>>> Server Port:            80
>>>>
>>>> Document Path:          /it-vis-animation.gif
>>>> Document Length:        8105309 bytes
>>>>
>>>> Concurrency Level:      100
>>>> Time taken for tests:   26.294 seconds
>>>> Complete requests:      2000
>>>> *Failed requests:        0*
>>>> Keep-Alive requests:    2000
>>>> Total transferred:      16211484000 bytes
>>>> HTML transferred:       16210618000 bytes
>>>> Requests per second:    76.06 [#/sec] (mean)
>>>> Time per request:       1314.691 [ms] (mean)
>>>> Time per request:       13.147 [ms] (mean, across all concurrent
>>>> requests)
>>>> Transfer rate:          602100.83 [Kbytes/sec] received
>>>>
>>>> Connection Times (ms)
>>>>               min  mean[+/-sd] median   max
>>>> Connect:        0    1   4.0      0      22
>>>> Processing:   404 1309  80.0   1298    1635
>>>> Waiting:        5   22  32.4     10     207
>>>> Total:        420 1310  80.6   1298    1635
>>>>
>>>> Percentage of the requests served within a certain time (ms)
>>>>   50%   1298
>>>>   66%   1315
>>>>   75%   1342
>>>>   80%   1360
>>>>   90%   1397
>>>>   95%   1440
>>>>   98%   1513
>>>>   99%   1530
>>>>  100%   1635 (longest request)
>>>>
>>>> *In this case I obtain always 0 failed!*
>>>>
>>>> *3) Using a little png file:*
>>>> *# ab -k -c 100 -n 2000 localhost/apple-touch-icon.png*
>>>> This is ApacheBench, Version 2.3 <$Revision: 1748469 $>
>>>> Copyright 1996 Adam Twiss, Zeus Technology Ltd,
>>>> http://www.zeustech.net/
>>>> Licensed to The Apache Software Foundation, http://www.apache.org/
>>>>
>>>> Benchmarking localhost (be patient)
>>>> Completed 200 requests
>>>> Completed 400 requests
>>>> Completed 600 requests
>>>> Completed 800 requests
>>>> Completed 1000 requests
>>>> Completed 1200 requests
>>>> Completed 1400 requests
>>>> Completed 1600 requests
>>>> Completed 1800 requests
>>>> Completed 2000 requests
>>>> Finished 2000 requests
>>>>
>>>>
>>>> Server Software:        Apache/2.4.23
>>>> Server Hostname:        localhost
>>>> Server Port:            80
>>>>
>>>> Document Path:          /apple-touch-icon.png
>>>> Document Length:        12364 bytes
>>>>
>>>> Concurrency Level:      100
>>>> Time taken for tests:   2.576 seconds
>>>> Complete requests:      2000
>>>> *Failed requests:        22*
>>>>    (Connect: 0, Receive: 0, Length: 22, Exceptions: 0)
>>>> Keep-Alive requests:    1978
>>>> Total transferred:      25304554 bytes
>>>> HTML transferred:       24455992 bytes
>>>> Requests per second:    776.52 [#/sec] (mean)
>>>> Time per request:       128.779 [ms] (mean)
>>>> Time per request:       1.288 [ms] (mean, across all concurrent
>>>> requests)
>>>> Transfer rate:          9594.53 [Kbytes/sec] received
>>>>
>>>> Connection Times (ms)
>>>>               min  mean[+/-sd] median   max
>>>> Connect:        0    1   3.9      0      20
>>>> Processing:     0  125 112.0    101     563
>>>> Waiting:        0  125 112.1    101     563
>>>> Total:          0  126 112.6    102     563
>>>>
>>>> Percentage of the requests served within a certain time (ms)
>>>>   50%    102
>>>>   66%    159
>>>>   75%    196
>>>>   80%    220
>>>>   90%    282
>>>>   95%    354
>>>>   98%    401
>>>>   99%    457
>>>>  100%    563 (longest request)
>>>>
>>>> *I get 22 failed requests, but if I run more again I obtain a different
>>>> number.*
>>>>
>>>> What do you thing?
>>>>
>>>> Thank you!
>>>>
>>>>
>>>>
>>>> 2016-09-30 13:50 GMT+02:00 Daniel <dferradal@gmail.com>:
>>>>
>>>>> hello,
>>>>>
>>>>> the fact that all those 500 error reponses go with "X-Powered-By:
>>>>> PHP/5.6.26" tell me it is php giving those errors.
>>>>>
>>>>> If you are still unsure, you could use the ab tool from Apache HTTPD,
>>>>> and request a specific static file (text, gif) hundreds of times to see
if
>>>>> you get a 500 error from HTTPD.
>>>>>
>>>>> 2016-09-30 8:59 GMT+02:00 Fabio F.Gervasi <fabio.gervasi70@gmail.com>:
>>>>>
>>>>>> Hi,
>>>>>>
>>>>>> I'm not 100% sure that the real source of the problem is apache
>>>>>> (could be php or other), but I'd like start from here as the only
logs that
>>>>>> provides me with information (with trace4 level) is apache log. No
>>>>>> information appears from other logs.
>>>>>>
>>>>>> I have:
>>>>>> - Linux 4.7.4-100.fc23.x86_64
>>>>>> - Server version: Apache/2.4.23 (Fedora)
>>>>>> - mysql  Ver 15.1 Distrib 10.0.26-MariaDB, for Linux (x86_64) using
>>>>>> readline 5.1
>>>>>> - PHP Version => 5.6.25
>>>>>>
>>>>>> The problem: random internal server error 500. Random because, for
>>>>>> example, if a page produces the error and do "reload" then it works.
The
>>>>>> same page may not work as well as work. Sometimes you can use the
site for
>>>>>> several minutes with no problems, then suddenly there is the error.
>>>>>>
>>>>>> When error occurs, this is all that I get from the log file (with
>>>>>> loglevel = trace4):
>>>>>>
>>>>>> [...]
>>>>>> [Fri Sep 30 07:41:39.151052 2016] [rewrite:trace3] [pid 17957:tid
>>>>>> 140241771534080] mod_rewrite.c(477): [client 151.25.206.200:38368]
>>>>>> 151.25.206.200 - - [www.centrometeo.com/sid#55c3e
>>>>>> 3673400][rid#7f8c8000e9d0/subreq
>>>>>> <http://www.centrometeo.com/sid#55c3e3673400][rid%237f8c8000e9d0/subreq>]
>>>>>> [perdir /home/web/centrometeo.com/] applying pattern '.*' to uri
>>>>>> 'index.php', referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.151092 2016] [rewrite:trace1] [pid 17957:tid
>>>>>> 140241771534080] mod_rewrite.c(477): [client 151.25.206.200:38368]
>>>>>> 151.25.206.200 - - [www.centrometeo.com/sid#55c3e
>>>>>> 3673400][rid#7f8c8000e9d0/subreq
>>>>>> <http://www.centrometeo.com/sid#55c3e3673400][rid%237f8c8000e9d0/subreq>]
>>>>>> [perdir /home/web/centrometeo.com/] pass through /home/web/
>>>>>> centrometeo.com/index.php, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913003 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(567): [client 151.25.206.200:38368]
>>>>>> Headers from script 'php.fcgi':, referer:
>>>>>> http://www.centrometeo.com/modelli-numerici/modello-wrf-nmm/
>>>>>> 559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913097 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(568): [client 151.25.206.200:38368]
  *Status:
>>>>>> 500 Internal Server Error*, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913130 2016] [core:trace1] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(649): [client 151.25.206.200:38368]
*Status
>>>>>> line from script 'php.fcgi': 500 Internal Server Error*, referer:
>>>>>> http://www.centrometeo.com/modelli-numerici/modello-wrf-nmm/
>>>>>> 559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913162 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(568): [client 151.25.206.200:38368]
>>>>>> X-Powered-By: PHP/5.6.26, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913191 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(568): [client 151.25.206.200:38368]
>>>>>> P3P: CP="NOI ADM DEV PSAi COM NAV OUR OTRo STP IND DEM", referer:
>>>>>> http://www.centrometeo.com/modelli-numerici/modello-wrf-nmm/
>>>>>> 559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913218 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(568): [client 151.25.206.200:38368]
>>>>>> Content-Encoding: gzip, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913246 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(568): [client 151.25.206.200:38368]
>>>>>> Vary: Accept-Encoding, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913275 2016] [core:trace4] [pid 17957:tid
>>>>>> 140241771534080] util_script.c(568): [client 151.25.206.200:38368]
>>>>>> Content-type: text/html; charset=UTF-8, referer:
>>>>>> http://www.centrometeo.com/modelli-numerici/modello-wrf-nmm/
>>>>>> 559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913395 2016] [http:trace3] [pid 17957:tid
>>>>>> 140241771534080] http_filters.c(1006): [client 151.25.206.200:38368]
*Response
>>>>>> sent with status 500, headers:*, referer:
>>>>>> http://www.centrometeo.com/modelli-numerici/modello-wrf-nmm/
>>>>>> 559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913432 2016] [http:trace4] [pid 17957:tid
>>>>>> 140241771534080] http_filters.c(835): [client 151.25.206.200:38368]
>>>>>>   X-Powered-By: PHP/5.6.26, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913458 2016] [http:trace4] [pid 17957:tid
>>>>>> 140241771534080] http_filters.c(835): [client 151.25.206.200:38368]
>>>>>>   P3P: CP=\\"NOI ADM DEV PSAi COM NAV OUR OTRo STP IND DEM\\", referer:
>>>>>> http://www.centrometeo.com/modelli-numerici/modello-wrf-nmm/
>>>>>> 559-wrf-mslp-6hprec-ita
>>>>>> [Fri Sep 30 07:41:39.913481 2016] [http:trace4] [pid 17957:tid
>>>>>> 140241771534080] http_filters.c(835): [client 151.25.206.200:38368]
>>>>>>   Content-Encoding: gzip, referer: http://www.centrometeo.com/mod
>>>>>> elli-numerici/modello-wrf-nmm/559-wrf-mslp-6hprec-ita
>>>>>> [...]
>>>>>>
>>>>>> Note the use of fcgi. Apache is indeed configured with
>>>>>> event/php-fpm/FastCGI, but the same thing happens with "normal" prefork
/
>>>>>> php!
>>>>>> Until a few days ago it did not happen, it started after updating
the
>>>>>> system (kernel, apache, php, mariadb).
>>>>>> I do not really know what to do.
>>>>>>
>>>>>> Thank you very much.
>>>>>> Fabio.
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> *Daniel Ferradal*
>>>>> IT Specialist
>>>>>
>>>>> email         dferradal at gmail.com
>>>>> linkedin     es.linkedin.com/in/danielferradal
>>>>>
>>>>
>>>>
>>>
>>
>>
>> --
>> *Daniel Ferradal*
>> IT Specialist
>>
>> email         dferradal at gmail.com
>> linkedin     es.linkedin.com/in/danielferradal
>>
>>
>>
>> -- The Wellcome Trust Sanger Institute is operated by Genome Research
>> Limited, a charity registered in England with number 1021457 and a company
>> registered in England with number 2742969, whose registered office is 215
>> Euston Road, London, NW1 2BE.
>>
>
>


-- 
*Daniel Ferradal*
IT Specialist

email         dferradal at gmail.com
linkedin     es.linkedin.com/in/danielferradal

Mime
View raw message