Hi Luca

On Sat, Jun 4, 2016 at 4:54 PM, Luca Toscano <toscano.l...@gmail.com> wrote:

>
> Can you post the list of modules that you have loaded plus your full httpd
> config (maybe you can upload them to the bug report)?  Another think to try
> would be to use gdb and http -X to trace one process, but it might be
> overkill. You could also try to add trace-log specific prints in the httpd
> .c files where Last-Modified is changed to see if anything comes up, but
> again it might be very time consuming.
>
> I tried to repro on 2.4.20 but I wasn't able, so I took a look to
> https://www.apache.org/dist/httpd/CHANGES_2.4 to see if it was something
> corrected with 2.4.13 but I didn't see anything obvious. You also mentioned
> that there seem to be no distro specific patches applied to the httpd
> package, so the issue might be really difficult to track.
>
> Will try to check you docker image during the next days, maybe we can come
> up with something. In the meantime, is there any possibility to switch to a
> different httpd version (that works) to unblock you?
>
> Luca
>
>
I hoped there might be some "obvious" configuration stuff that might
affected the behaviour but it seems to be a very specific bug.
I don't know how to use gdb in this situation, if you have any hint, I
would be happy to give it a try.

I will start by rebuilding the package without the patches to see where the
things starts to get bad.

For what is worth, I tried with an updated version of the package (based on
2.4.18) and I got the same result. Here is the new trace:
[Mon Jun 06 11:32:41.663635 2016] [suexec:notice] [pid 55] AH01232: suEXEC
mechanism enabled (wrapper: /opt/rh/httpd24/root/usr/sbin/suexec)
[Mon Jun 06 11:32:41.671425 2016] [auth_digest:notice] [pid 56] AH01757:
generating secret for digest authentication ...
[Mon Jun 06 11:32:41.671568 2016] [http2:warn] [pid 56] AH02951: mod_ssl
does not seem to be enabled
[Mon Jun 06 11:32:41.672107 2016] [lbmethod_heartbeat:notice] [pid 56]
AH02282: No slotmem from mod_heartmonitor
[Mon Jun 06 11:32:41.674127 2016] [mpm_prefork:notice] [pid 56] AH00163:
Apache/2.4.18 (Red Hat) configured -- resuming normal operations
[Mon Jun 06 11:32:41.674150 2016] [core:notice] [pid 56] AH00094: Command
line: '/opt/rh/httpd24/root/usr/sbin/httpd'
[Mon Jun 06 11:32:41.676422 2016] [http2:trace1] [pid 58] h2_h2.c(596):
[client ::1:59372] h2_h2, process_conn
[Mon Jun 06 11:32:41.676473 2016] [core:trace5] [pid 58] protocol.c(616):
[client ::1:59372] Request received from client: GET /headers.php HTTP/1.1
[Mon Jun 06 11:32:41.676497 2016] [http:trace4] [pid 58]
http_request.c(394): [client ::1:59372] Headers received from client:
[Mon Jun 06 11:32:41.676501 2016] [http:trace4] [pid 58]
http_request.c(398): [client ::1:59372]   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
[Mon Jun 06 11:32:41.676503 2016] [http:trace4] [pid 58]
http_request.c(398): [client ::1:59372]   Host: localhost
[Mon Jun 06 11:32:41.676505 2016] [http:trace4] [pid 58]
http_request.c(398): [client ::1:59372]   Accept: */*
[Mon Jun 06 11:32:41.676634 2016] [authz_core:debug] [pid 58]
mod_authz_core.c(809): [client ::1:59372] AH01626: authorization result of
Require all granted: granted
[Mon Jun 06 11:32:41.676644 2016] [authz_core:debug] [pid 58]
mod_authz_core.c(809): [client ::1:59372] AH01626: authorization result of
<RequireAny>: granted
[Mon Jun 06 11:32:41.676646 2016] [core:trace3] [pid 58] request.c(293):
[client ::1:59372] request authorized without authentication by
access_checker_ex hook: /headers.php
[Mon Jun 06 11:32:41.676718 2016] [proxy:trace2] [pid 58]
proxy_util.c(1989): [client ::1:59372] *: using default reverse proxy
worker for fcgi://
127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php (no keepalive)
[Mon Jun 06 11:32:41.676724 2016] [proxy:debug] [pid 58] mod_proxy.c(1160):
[client ::1:59372] AH01143: Running scheme fcgi handler (attempt 0)
[Mon Jun 06 11:32:41.676728 2016] [proxy_ajp:debug] [pid 58]
mod_proxy_ajp.c(738): [client ::1:59372] AH00894: declining URL fcgi://
127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php
[Mon Jun 06 11:32:41.676731 2016] [proxy_fcgi:debug] [pid 58]
mod_proxy_fcgi.c(879): [client ::1:59372] AH01076: url: fcgi://
127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php proxyname:
(null) proxyport: 0
[Mon Jun 06 11:32:41.676734 2016] [proxy_fcgi:debug] [pid 58]
mod_proxy_fcgi.c(886): [client ::1:59372] AH01078: serving URL fcgi://
127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php
[Mon Jun 06 11:32:41.676737 2016] [proxy:debug] [pid 58]
proxy_util.c(2160): AH00942: FCGI: has acquired connection for (*)
[Mon Jun 06 11:32:41.676743 2016] [proxy:debug] [pid 58]
proxy_util.c(2213): [client ::1:59372] AH00944: connecting fcgi://
127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php to
127.0.0.1:9000
[Mon Jun 06 11:32:41.676782 2016] [proxy:debug] [pid 58]
proxy_util.c(2422): [client ::1:59372] AH00947: connected
/opt/rh/httpd24/root/var/www/html/headers.php to 127.0.0.1:9000
[Mon Jun 06 11:32:41.676791 2016] [proxy:trace2] [pid 58]
proxy_util.c(2765): FCGI: fam 2 socket created to connect to *
[Mon Jun 06 11:32:41.676846 2016] [proxy:debug] [pid 58]
proxy_util.c(2799): AH02824: FCGI: connection established with
127.0.0.1:9000 (*)
[Mon Jun 06 11:32:41.676882 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'UNIQUE_ID' value 'AAAAAKxJoyMmnHek7RDFUQAAAAA'
[Mon Jun 06 11:32:41.676888 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'proxy-nokeepalive' value '1'
[Mon Jun 06 11:32:41.676895 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] 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'
[Mon Jun 06 11:32:41.676898 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'HTTP_HOST' value 'localhost'
[Mon Jun 06 11:32:41.676900 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'HTTP_ACCEPT' value '*/*'
[Mon Jun 06 11:32:41.676902 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var 'PATH'
value
'/opt/rh/httpd24/root/usr/bin:/opt/rh/httpd24/root/usr/sbin:/sbin:/usr/sbin:/bin:/usr/bin'
[Mon Jun 06 11:32:41.676904 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'LD_LIBRARY_PATH' value '/opt/rh/httpd24/root/usr/lib64'
[Mon Jun 06 11:32:41.676906 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_SIGNATURE' value ''
[Mon Jun 06 11:32:41.676908 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_SOFTWARE' value 'Apache/2.4.18 (Red Hat)'
[Mon Jun 06 11:32:41.676910 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_NAME' value 'localhost'
[Mon Jun 06 11:32:41.676912 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_ADDR' value '::1'
[Mon Jun 06 11:32:41.676914 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_PORT' value '80'
[Mon Jun 06 11:32:41.676916 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'REMOTE_ADDR' value '::1'
[Mon Jun 06 11:32:41.676918 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'DOCUMENT_ROOT' value '/opt/rh/httpd24/root/var/www/html'
[Mon Jun 06 11:32:41.676920 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'REQUEST_SCHEME' value 'http'
[Mon Jun 06 11:32:41.676922 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'CONTEXT_PREFIX' value ''
[Mon Jun 06 11:32:41.676924 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'CONTEXT_DOCUMENT_ROOT' value '/opt/rh/httpd24/root/var/www/html'
[Mon Jun 06 11:32:41.676926 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_ADMIN' value 'root@localhost'
[Mon Jun 06 11:32:41.676928 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SCRIPT_FILENAME' value 'proxy:fcgi://
127.0.0.1:9000/opt/rh/httpd24/root/var/www/html/headers.php'
[Mon Jun 06 11:32:41.676930 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'REMOTE_PORT' value '59372'
[Mon Jun 06 11:32:41.676932 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'GATEWAY_INTERFACE' value 'CGI/1.1'
[Mon Jun 06 11:32:41.676934 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SERVER_PROTOCOL' value 'HTTP/1.1'
[Mon Jun 06 11:32:41.676936 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'REQUEST_METHOD' value 'GET'
[Mon Jun 06 11:32:41.676938 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'QUERY_STRING' value ''
[Mon Jun 06 11:32:41.676940 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'REQUEST_URI' value '/headers.php'
[Mon Jun 06 11:32:41.676942 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(294): [client ::1:59372] AH01062: sending env var
'SCRIPT_NAME' value '/headers.php'
[Mon Jun 06 11:32:41.677447 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(578): [client ::1:59372] FastCGI header (8 bytes)
[Mon Jun 06 11:32:41.677456 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(578): [client ::1:59372] .....W..         0106000100570100

[Mon Jun 06 11:32:41.677462 2016] [proxy_fcgi:trace4] [pid 58]
util_script.c(544): [client ::1:59372] Headers from script 'headers.php':
[Mon Jun 06 11:32:41.677465 2016] [proxy_fcgi:trace4] [pid 58]
util_script.c(545): [client ::1:59372]   X-Powered-By: PHP/5.6.5
[Mon Jun 06 11:32:41.677468 2016] [proxy_fcgi:trace4] [pid 58]
util_script.c(545): [client ::1:59372]   Last-Modified: foo
[Mon Jun 06 11:32:41.677477 2016] [proxy_fcgi:trace4] [pid 58]
util_script.c(545): [client ::1:59372]   Content-type: text/html;
charset=UTF-8
[Mon Jun 06 11:32:41.677483 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(578): [client ::1:59372] FastCGI header (8 bytes)
[Mon Jun 06 11:32:41.677485 2016] [proxy_fcgi:trace8] [pid 58]
mod_proxy_fcgi.c(578): [client ::1:59372] ........         0103000100080000

[Mon Jun 06 11:32:41.677488 2016] [proxy:debug] [pid 58]
proxy_util.c(2175): AH00943: FCGI: has released connection for (*)
[Mon Jun 06 11:32:41.677523 2016] [http:trace3] [pid 58]
http_filters.c(1006): [client ::1:59372] Response sent with status 200,
headers:
[Mon Jun 06 11:32:41.677527 2016] [http:trace5] [pid 58]
http_filters.c(1013): [client ::1:59372]   Date: Mon, 06 Jun 2016 11:32:41
GMT
[Mon Jun 06 11:32:41.677529 2016] [http:trace5] [pid 58]
http_filters.c(1016): [client ::1:59372]   Server: Apache/2.4.18 (Red Hat)
[Mon Jun 06 11:32:41.677532 2016] [http:trace4] [pid 58]
http_filters.c(835): [client ::1:59372]   X-Powered-By: PHP/5.6.5
[Mon Jun 06 11:32:41.677534 2016] [http:trace4] [pid 58]
http_filters.c(835): [client ::1:59372]   Last-Modified: Thu, 01 Jan 1970
00:00:00 GMT
[Mon Jun 06 11:32:41.677536 2016] [http:trace4] [pid 58]
http_filters.c(835): [client ::1:59372]   Content-Length: 0
[Mon Jun 06 11:32:41.677538 2016] [http:trace4] [pid 58]
http_filters.c(835): [client ::1:59372]   Content-Type: text/html;
charset=UTF-8
[Mon Jun 06 11:32:41.677552 2016] [core:trace6] [pid 58]
core_filters.c(525): [client ::1:59372] core_output_filter: flushing
because of FLUSH bucket
[Mon Jun 06 11:32:41.677691 2016] [core:trace6] [pid 58]
core_filters.c(525): [client ::1:59372] core_output_filter: flushing
because of FLUSH bucket

Reply via email to