Bug 1757683 - httpd stuck reading from CGI
Summary: httpd stuck reading from CGI
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: httpd
Version: 30
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Luboš Uhliarik
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1757196 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-10-02 07:31 UTC by David Woodhouse
Modified: 2019-10-12 01:29 UTC (History)
6 users (show)

Fixed In Version: httpd-2.4.41-4.fc29 httpd-2.4.41-5.fc31 httpd-2.4.41-5.fc30 httpd-2.4.41-5.fc29
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-10-08 00:26:50 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description David Woodhouse 2019-10-02 07:31:00 UTC
For the last few weeks, httpd on {git,lists}.infradead.org has periodically become stuck and stopped responding.  I upgraded to httpd-2.4.41-1.fc30 (from 2.4.39-4) on September 11th; it could well have started then.

Running 'systemctl status httpd' shows a lot of gitweb.cgi children. Tracing them shows they're trying to write output through a pipe back to httpd. I don't know if this is relevant to the problem; it might even have been like this before and I hadn't noticed. 


● httpd.service - The Apache HTTP Server
   Loaded: loaded (/usr/lib/systemd/system/httpd.service; enabled; vendor preset: disabled)
  Drop-In: /usr/lib/systemd/system/httpd.service.d
           └─php-fpm.conf
   Active: active (running) since Sun 2019-09-29 09:39:08 PDT; 2 days ago
     Docs: man:httpd.service(8)
 Main PID: 16563 (httpd)
   Status: "Total requests: 100159; Idle/Busy workers 4/96;Requests/sec: 0.446; Bytes served/sec: 7.9KB/sec"
    Tasks: 1443 (limit: 4915)
   Memory: 5.3G
   CGroup: /system.slice/httpd.service
           ├─  581 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  623 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  712 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  718 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  779 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  780 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  901 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─  929 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1021 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1075 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1109 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1162 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1191 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1196 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1197 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1226 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1228 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1389 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1484 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1485 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1849 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 1880 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2027 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2252 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2363 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2370 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2497 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2560 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2586 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2587 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2609 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2623 /usr/bin/perl /var/www/git/gitweb.cgi
           ├─ 2787 /usr/bin/perl /var/www/git/gitweb.cgi


strace: Process 31367 attached
write(1, ".git/log\">log</a> | <a href=\"/us"..., 8192^Cstrace: Process 31367 detached

Comment 1 Joe Orton 2019-10-02 08:38:53 UTC
We changed CGI stderr handling in the latest update so it's probably related & a regression.

Anything non-standard in the config, anything interesting in /var/log/httpd/error_log?

Comment 2 David Woodhouse 2019-10-02 09:52:47 UTC
The config is fairly standard:

<VirtualHost *:80>
	ServerName git.infradead.org
	DocumentRoot /var/www/git
	Alias /robots.txt /var/www/git/static/robots.txt
        <Directory /var/www/git>
                Options +ExecCGI
                AddHandler cgi-script cgi

                DirectoryIndex gitweb.cgi

                RewriteEngine On
                RewriteCond %{REQUEST_FILENAME} !-f
                RewriteCond %{REQUEST_FILENAME} !-d
                RewriteRule ^.* /gitweb.cgi/$0 [L,PT]
        </Directory>
</VirtualHost>


I see these in logs (along with lots of other things that don't seem abnormal, and some that do but are correlated with my 'killall gitweb.cgi'. Will try to get something correlated with a specific event and misbehaving child.

[Wed Oct 02 01:21:39.911249 2019] [cgid:warn] [pid 11096:tid 140026738374400] [client 111.202.100.85:47553] AH01220: Timeout waiting for output from CGI script /var/www/git/gitweb.cgi
[Wed Oct 02 01:21:39.911331 2019] [core:error] [pid 11096:tid 140026738374400] (70007)The timeout specified has expired: [client 111.202.100.85:47553] AH00574: ap_content_length_filter: apr_bucket_read() failed
[Wed Oct 02 01:23:49.276596 2019] [cgid:warn] [pid 11096:tid 140026662840064] [client 111.202.100.85:34962] AH01220: Timeout waiting for output from CGI script /var/www/git/gitweb.cgi
[Wed Oct 02 01:23:49.326259 2019] [cgid:error] [pid 11096:tid 140026662840064] [client 111.202.100.85:34962] Script timed out before returning headers: gitweb.cgi
[Wed Oct 02 01:24:49.375809 2019] [cgid:warn] [pid 11096:tid 140026662840064] [client 111.202.100.85:34962] AH01220: Timeout waiting for output from CGI script /var/www/git/gitweb.cgi
[Wed Oct 02 01:26:00.853221 2019] [cgid:warn] [pid 30783:tid 140026327328512] [client 111.202.100.85:62428] AH01220: Timeout waiting for output from CGI script /var/www/git/gitweb.cgi
[Wed Oct 02 01:26:00.853300 2019] [core:error] [pid 30783:tid 140026327328512] (70007)The timeout specified has expired: [client 111.202.100.85:62428] AH00574: ap_content_length_filter: apr_bucket_read() failed

Comment 3 Joe Orton 2019-10-02 10:11:49 UTC
*** Bug 1757196 has been marked as a duplicate of this bug. ***

Comment 4 customercare 2019-10-02 10:32:20 UTC
If i may:

it started exactly with 2.4.41, reverting to 2.39.3 stopped it.

There were no helpful messages inside error_log. PHP just gets stuck in write(). I know, not helpfull, but thats what happening.

"We" used PHP via AddHandler and a cgiwrapper ( user based privilege seperation and chroot ) and noticed, that it only happens,
when large chunks of data should be read from the cgi script. In our case, we generated PDF files with >500k. All other, smaller php outputs, like Wordpress html pages, worked as expected.

It's reliable stucking, should be easy to find. More infos in Bug 1757196 if needed.

Comment 6 Joe Orton 2019-10-02 11:03:03 UTC
Package: httpd-2.4.41-4.fc32

Comment 7 Joe Orton 2019-10-02 11:11:13 UTC
A bit speculative this fixes the problem, but the above removes one difference between mod_cgi and mod_cgid using the new stderr handling.  I'm building for f30.

Comment 8 Joe Orton 2019-10-02 11:28:07 UTC
Package: httpd-2.4.41-4.fc30

Comment 9 Joe Orton 2019-10-02 11:52:19 UTC
f30 build: https://koji.fedoraproject.org/koji/buildinfo?buildID=1393459

would be useful to test but I haven't reproduced this so not confirmed the fix yet.

Comment 10 customercare 2019-10-02 12:47:40 UTC
if you build a F29 version, i can check it.

Comment 11 Joe Orton 2019-10-02 13:25:53 UTC
Package: httpd-2.4.41-4.fc29

Comment 12 customercare 2019-10-02 13:34:53 UTC
*FIX CONFIRMED*

Comment 13 Fedora Update System 2019-10-03 09:41:05 UTC
FEDORA-2019-d0255b7710 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-d0255b7710

Comment 14 Fedora Update System 2019-10-03 09:41:14 UTC
FEDORA-2019-c39b063554 has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2019-c39b063554

Comment 15 David Woodhouse 2019-10-03 16:05:06 UTC
Seems fixed here with the koji build from comment #9.

Comment 16 Joe Orton 2019-10-04 06:58:23 UTC
Thanks a lot folks for testing this!

Comment 17 Fedora Update System 2019-10-04 22:14:20 UTC
httpd-2.4.41-5.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-d0255b7710

Comment 18 Fedora Update System 2019-10-04 22:50:12 UTC
httpd-2.4.41-5.fc31 has been pushed to the Fedora 31 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-c39b063554

Comment 19 Fedora Update System 2019-10-04 23:08:47 UTC
httpd-2.4.41-5.fc29 has been pushed to the Fedora 29 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-8df80552fc

Comment 20 Fedora Update System 2019-10-08 00:26:50 UTC
httpd-2.4.41-5.fc31 has been pushed to the Fedora 31 stable repository. If problems still persist, please make note of it in this bug report.

Comment 21 Fedora Update System 2019-10-09 16:53:31 UTC
httpd-2.4.41-5.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.

Comment 22 Fedora Update System 2019-10-12 01:29:05 UTC
httpd-2.4.41-5.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.