Bug 1341232

Summary:	httpd24 rewrites Last-Modified header
Product:	Red Hat Enterprise Linux 7	Reporter:	manuel.vacelet
Component:	httpd	Assignee:	Luboš Uhliarik <luhliari>
Status:	CLOSED WONTFIX	QA Contact:
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	7.4	CC:	jorton
Target Milestone:	rc
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2020-01-16 10:26:44 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description manuel.vacelet 2016-05-31 13:50:37 UTC

Description of problem:
I have a php application that sets "Last-Modified" header.

When the value is not compliant to RFC it's rewritten to "Last-Modified: Thu, 01 Jan 1970 00:00:00 GMT" (reproducibility: 100%)

I also noticed that, when the value follow the RFC and is close to "current time", I sometime have a small difference (~ 1 to 3 seconds) between the value sent by the php script and the value received by the client. (reproducibility: 20%)

I only reproduce the problem with SCL httpd24-httpd

Version-Release number of selected component (if applicable):
httpd24-httpd 2.4.12 on centos6

How reproducible:


Steps to Reproduce:
I created a small docker image that reproduce the issue https://github.com/vaceletm/bug-httpd24

manuel@tortue:~$ docker run -ti --rm httpdbug
Starting php-fpm: [ OK ]
Starting httpd: AH00558: httpd: Could not reliably determine the server's fully qualified domain name, using 172.17.42.2. Set the 'ServerName' directive globally to suppress this message
                                                           [ OK ]
* About to connect() to localhost port 80 (#0)
* Trying ::1... connected
* Connected to localhost (::1) port 80 (#0)
> GET /headers.php HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: localhost
> Accept: */*
>
< HTTP/1.1 200 OK
< Date: Mon, 30 May 2016 10:36:28 GMT
< Server: Apache/2.4.12 (Red Hat)
< X-Powered-By: PHP/5.6.5
< Last-Modified: Thu, 01 Jan 1970 00:00:00 GMT
< Content-Length: 0
< Content-Type: text/html; charset=UTF-8
<
* Connection #0 to host localhost left intact
* Closing connection #0

Last modified header is not the one set by php script.


Additional info:
The headers are not rewritten when the page is served through:
- rh-nginx18 (scl / centos6)
- mod_php with httpd22 (centos6 base)
- mod_php with httpd25 (centos7 base)

Comment 1 Petr Pisar 2016-06-01 05:50:32 UTC

*** Bug 1341233 has been marked as a duplicate of this bug. ***

Comment 2 manuel.vacelet 2016-06-03 12:30:16 UTC

I still reproduce the issue with httpd24-httpd-2.4.18-10.el6 (https://github.com/vaceletm/bug-httpd24)

curl -v http://localhost/headers.php
* About to connect() to localhost port 80 (#0)
*   Trying ::1... connected
* Connected to localhost (::1) port 80 (#0)
> GET /headers.php HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: localhost
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Fri, 03 Jun 2016 12:25:34 GMT
< Server: Apache/2.4.18 (Red Hat)
< X-Powered-By: PHP/5.6.5
< Last-Modified: Thu, 01 Jan 1970 00:00:00 GMT
< Content-Length: 0
< Content-Type: text/html; charset=UTF-8
< 
* Connection #0 to host localhost left intact
* Closing connection #0


and I added more log and logs are clearly telling that fpm sends the header but apache sends another one:


[Fri Jun 03 12:25:34.850855 2016] [suexec:notice] [pid 46] AH01232: suEXEC mechanism enabled (wrapper: /opt/rh/httpd24/root/usr/sbin/suexec)
[Fri Jun 03 12:25:34.862540 2016] [auth_digest:notice] [pid 47] AH01757: generating secret for digest authentication ...
[Fri Jun 03 12:25:34.862821 2016] [http2:warn] [pid 47] AH02951: mod_ssl does not seem to be enabled
[Fri Jun 03 12:25:34.863497 2016] [lbmethod_heartbeat:notice] [pid 47] AH02282: No slotmem from mod_heartmonitor
[Fri Jun 03 12:25:34.866234 2016] [mpm_prefork:notice] [pid 47] AH00163: Apache/2.4.18 (Red Hat) configured -- resuming normal operations
[Fri Jun 03 12:25:34.866261 2016] [core:notice] [pid 47] AH00094: Command line: '/opt/rh/httpd24/root/usr/sbin/httpd'
[Fri Jun 03 12:25:34.871099 2016] [http2:trace1] [pid 49] h2_h2.c(596): [client ::1:38606] h2_h2, process_conn
[Fri Jun 03 12:25:34.871140 2016] [core:trace5] [pid 49] protocol.c(616): [client ::1:38606] Request received from client: GET /headers.php HTTP/1.1
[Fri Jun 03 12:25:34.871160 2016] [http:trace4] [pid 49] http_request.c(394): [client ::1:38606] Headers received from client:
[Fri Jun 03 12:25:34.871163 2016] [http:trace4] [pid 49] http_request.c(398): [client ::1:38606]   User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
[Fri Jun 03 12:25:34.871166 2016] [http:trace4] [pid 49] http_request.c(398): [client ::1:38606]   Host: localhost
[Fri Jun 03 12:25:34.871168 2016] [http:trace4] [pid 49] http_request.c(398): [client ::1:38606]   Accept: */*
[Fri Jun 03 12:25:34.871347 2016] [authz_core:debug] [pid 49] mod_authz_core.c(809): [client ::1:38606] AH01626: authorization result of Require all granted: granted
[Fri Jun 03 12:25:34.871354 2016] [authz_core:debug] [pid 49] mod_authz_core.c(809): [client ::1:38606] AH01626: authorization result of <RequireAny>: granted
[Fri Jun 03 12:25:34.871356 2016] [core:trace3] [pid 49] request.c(293): [client ::1:38606] request authorized without authentication by access_checker_ex hook: /headers.php
[Fri Jun 03 12:25:34.871457 2016] [proxy:trace2] [pid 49] proxy_util.c(1989): [client ::1:38606] *: using default reverse proxy worker for fcgi://127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php (no keepalive)
[Fri Jun 03 12:25:34.871462 2016] [proxy:debug] [pid 49] mod_proxy.c(1160): [client ::1:38606] AH01143: Running scheme fcgi handler (attempt 0)
[Fri Jun 03 12:25:34.871469 2016] [proxy_ajp:debug] [pid 49] mod_proxy_ajp.c(738): [client ::1:38606] AH00894: declining URL fcgi://127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php
[Fri Jun 03 12:25:34.871475 2016] [proxy_fcgi:debug] [pid 49] mod_proxy_fcgi.c(879): [client ::1:38606] AH01076: url: fcgi://127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php proxyname: (null) proxyport: 0
[Fri Jun 03 12:25:34.871478 2016] [proxy_fcgi:debug] [pid 49] mod_proxy_fcgi.c(886): [client ::1:38606] AH01078: serving URL fcgi://127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php
[Fri Jun 03 12:25:34.871481 2016] [proxy:debug] [pid 49] proxy_util.c(2160): AH00942: FCGI: has acquired connection for (*)
[Fri Jun 03 12:25:34.871487 2016] [proxy:debug] [pid 49] proxy_util.c(2213): [client ::1:38606] AH00944: connecting fcgi://127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php to 127.0.0.1:9000
[Fri Jun 03 12:25:34.871522 2016] [proxy:debug] [pid 49] proxy_util.c(2422): [client ::1:38606] AH00947: connected /opt/rh/httpd24/root/var/www/html/headers.php to 127.0.0.1:9000
[Fri Jun 03 12:25:34.871530 2016] [proxy:trace2] [pid 49] proxy_util.c(2765): FCGI: fam 2 socket created to connect to *
[Fri Jun 03 12:25:34.871605 2016] [proxy:debug] [pid 49] proxy_util.c(2799): AH02824: FCGI: connection established with 127.0.0.1:9000 (*)
[Fri Jun 03 12:25:34.871645 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'UNIQUE_ID' value 'AAAAAHPKueV4-AQtflB7HgAAAAA'
[Fri Jun 03 12:25:34.871649 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'proxy-nokeepalive' value '1'
[Fri Jun 03 12:25:34.871659 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'HTTP_USER_AGENT' value 'curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2'
[Fri Jun 03 12:25:34.871662 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'HTTP_HOST' value 'localhost'
[Fri Jun 03 12:25:34.871664 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'HTTP_ACCEPT' value '*/*'
[Fri Jun 03 12:25:34.871666 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'PATH' value '/opt/rh/httpd24/root/usr/bin:/opt/rh/httpd24/root/usr/sbin:/sbin:/usr/sbin:/bin:/usr/bin'
[Fri Jun 03 12:25:34.871668 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'LD_LIBRARY_PATH' value '/opt/rh/httpd24/root/usr/lib64'
[Fri Jun 03 12:25:34.871670 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_SIGNATURE' value ''
[Fri Jun 03 12:25:34.871672 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_SOFTWARE' value 'Apache/2.4.18 (Red Hat)'
[Fri Jun 03 12:25:34.871674 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_NAME' value 'localhost'
[Fri Jun 03 12:25:34.871676 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_ADDR' value '::1'
[Fri Jun 03 12:25:34.871678 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_PORT' value '80'
[Fri Jun 03 12:25:34.871680 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'REMOTE_ADDR' value '::1'
[Fri Jun 03 12:25:34.871682 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'DOCUMENT_ROOT' value '/opt/rh/httpd24/root/var/www/html'
[Fri Jun 03 12:25:34.871684 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'REQUEST_SCHEME' value 'http'
[Fri Jun 03 12:25:34.871686 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'CONTEXT_PREFIX' value ''
[Fri Jun 03 12:25:34.871688 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'CONTEXT_DOCUMENT_ROOT' value '/opt/rh/httpd24/root/var/www/html'
[Fri Jun 03 12:25:34.871690 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_ADMIN' value 'root@localhost'
[Fri Jun 03 12:25:34.871692 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SCRIPT_FILENAME' value 'proxy:fcgi://127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php'
[Fri Jun 03 12:25:34.871694 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'REMOTE_PORT' value '38606'
[Fri Jun 03 12:25:34.871696 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'GATEWAY_INTERFACE' value 'CGI/1.1'
[Fri Jun 03 12:25:34.871698 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SERVER_PROTOCOL' value 'HTTP/1.1'
[Fri Jun 03 12:25:34.871700 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'REQUEST_METHOD' value 'GET'
[Fri Jun 03 12:25:34.871702 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'QUERY_STRING' value ''
[Fri Jun 03 12:25:34.871703 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'REQUEST_URI' value '/headers.php'
[Fri Jun 03 12:25:34.871705 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(294): [client ::1:38606] AH01062: sending env var 'SCRIPT_NAME' value '/headers.php'
[Fri Jun 03 12:25:34.872190 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(578): [client ::1:38606] FastCGI header (8 bytes)
[Fri Jun 03 12:25:34.872204 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(578): [client ::1:38606] .....W..         0106000100570100                
[Fri Jun 03 12:25:34.872211 2016] [proxy_fcgi:trace4] [pid 49] util_script.c(544): [client ::1:38606] Headers from script 'headers.php':
[Fri Jun 03 12:25:34.872215 2016] [proxy_fcgi:trace4] [pid 49] util_script.c(545): [client ::1:38606]   X-Powered-By: PHP/5.6.5
[Fri Jun 03 12:25:34.872218 2016] [proxy_fcgi:trace4] [pid 49] util_script.c(545): [client ::1:38606]   Last-Modified: foo
[Fri Jun 03 12:25:34.872226 2016] [proxy_fcgi:trace4] [pid 49] util_script.c(545): [client ::1:38606]   Content-type: text/html; charset=UTF-8
[Fri Jun 03 12:25:34.872232 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(578): [client ::1:38606] FastCGI header (8 bytes)
[Fri Jun 03 12:25:34.872235 2016] [proxy_fcgi:trace8] [pid 49] mod_proxy_fcgi.c(578): [client ::1:38606] ........         0103000100080000                
[Fri Jun 03 12:25:34.872238 2016] [proxy:debug] [pid 49] proxy_util.c(2175): AH00943: FCGI: has released connection for (*)
[Fri Jun 03 12:25:34.872279 2016] [http:trace3] [pid 49] http_filters.c(1006): [client ::1:38606] Response sent with status 200, headers:
[Fri Jun 03 12:25:34.872285 2016] [http:trace5] [pid 49] http_filters.c(1013): [client ::1:38606]   Date: Fri, 03 Jun 2016 12:25:34 GMT
[Fri Jun 03 12:25:34.872288 2016] [http:trace5] [pid 49] http_filters.c(1016): [client ::1:38606]   Server: Apache/2.4.18 (Red Hat)
[Fri Jun 03 12:25:34.872292 2016] [http:trace4] [pid 49] http_filters.c(835): [client ::1:38606]   X-Powered-By: PHP/5.6.5
[Fri Jun 03 12:25:34.872295 2016] [http:trace4] [pid 49] http_filters.c(835): [client ::1:38606]   Last-Modified: Thu, 01 Jan 1970 00:00:00 GMT
[Fri Jun 03 12:25:34.872298 2016] [http:trace4] [pid 49] http_filters.c(835): [client ::1:38606]   Content-Length: 0
[Fri Jun 03 12:25:34.872301 2016] [http:trace4] [pid 49] http_filters.c(835): [client ::1:38606]   Content-Type: text/html; charset=UTF-8
[Fri Jun 03 12:25:34.872317 2016] [core:trace6] [pid 49] core_filters.c(525): [client ::1:38606] core_output_filter: flushing because of FLUSH bucket
[Fri Jun 03 12:25:34.872527 2016] [core:trace6] [pid 49] core_filters.c(525): [client ::1:38606] core_output_filter: flushing because of FLUSH bucket

Comment 3 manuel.vacelet 2016-06-06 15:59:14 UTC

I re-qualify the bug to RHEL7 / httpd as the bug also affect the default distribution.

Please note that it seems to be specific to fastcgi as the same script served by mod_php works as expected.

Comment 5 Joe Orton 2016-06-06 16:39:42 UTC

Thank you for taking the time to report this issue to us. We appreciate the feedback and use reports such as this one to guide our efforts at improving our products. That being said, this bug tracking system is not a mechanism for requesting support, and we are not able to guarantee the timeliness or suitability of a resolution.

If this issue is critical or in any way time sensitive, please raise a ticket through the regular Red Hat support channels to ensure it receives the proper attention and prioritization to assure a timely resolution. 

For information on how to contact the Red Hat production support team, please visit: https://www.redhat.com/support/process/production/

Comment 10 RHEL Program Management 2020-01-16 10:26:44 UTC

Development Management has reviewed and declined this request. You may appeal this decision by using your Red Hat support channels, who will make certain  the issue receives the proper prioritization with product and development management.

https://www.redhat.com/support/process/production/#howto