osdir.com


[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[Bug 61147] New: Truncated response from mod_proxy


https://bz.apache.org/bugzilla/show_bug.cgi?id=61147

            Bug ID: 61147
           Summary: Truncated response from mod_proxy
           Product: Apache httpd-2
           Version: 2.4.25
          Hardware: PC
                OS: Linux
            Status: NEW
          Severity: major
          Priority: P2
         Component: mod_proxy
          Assignee: bugs@xxxxxxxxxxxxxxxx
          Reporter: ruben.degraaf@xxxxxxxxxxxxxxxxxx
  Target Milestone: ---

Created attachment 35028
  --> https://bz.apache.org/bugzilla/attachment.cgi?id=35028&action=edit
both full and truncated response

Hello,

I've struggled with this bug for some days now, so this is what I've discovered
:

The bug is present in the following versions :

Apache/2.2.15 (compiled by redhat - the one for RHEL 6.9)
Apache/2.4.7 (compiled by redhat - the one for RHEL 7.3)
Apache/2.4.25 (compiled by IUS community =
https://github.com/iuscommunity-pkg/httpd24u)

So what I'm doing is interrogating a webservice running on a wildfly 10.0 Final
server and the reply I have when I directly interrogate the server is the
attached file called full response.txt

Now when I put a server running mod_proxy (any from the 3 versions above) in
front of the server, the response I get is the attached file called truncated
response.txt

I do catch an error in the httpd logs and it's the following one :

[proxy_http:error] [pid 15142] (70008)Partial results are valid but processing
is incomplete: [client 192.168.123.4:37489] AH01110: error reading response

Just for information, the response is a pdf file encapsulated in xml and WE DO
HAVE THE ISSUE FOR SOME FILES ONLY, NOT ALL OF THEM. 

(Sorry for caps, but the text editing in this bug report tool is a bit basic)

My configuration of mod_proxy is pretty basic :

<VirtualHost 192.168.171.202:80>

        ProxyPass / http://s-docweb-qua-01:8080/
        ProxyPassReverse / http://s-docweb-qua-01:8080/
        ProxyPass /web-console !
        ProxyPass /admin-console !
        ProxyPass /jmx-console !
        ProxyPass /jbossws !
        ProxyPass /error/ !
        ProxyPass /usage !
        ProxyPass /mod_cluster_manager !

        <Location />
        Require all granted
        </Location>

        <Location /mod_cluster_manager>
            SetHandler mod_cluster-manager
            Require all granted
        </Location>

    CustomLog "/var/log/httpd/docweb-vip-qua-01_request_log" "%t %h \"%r\" %b
**%T/%D**"
    ErrorLog "/var/log/httpd/docweb-vip-qua-01_error_log"
    TransferLog "/var/log/httpd/docweb-vip-qua-01_access_log"
    LogLevel trace8

</VirtualHost>



The file posted to get the response from the webservice is the following one :

<soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/";
xmlns:sch="http://www.internalwebsite.com/de/docweb/envoiDocument/schemas";>
   <soapenv:Header/>
   <soapenv:Body>
      <sch:GetDocumentByTraitementIdRequestElement>
         <sch:traitementId>9905</sch:traitementId>
      </sch:GetDocumentByTraitementIdRequestElement>
   </soapenv:Body>
</soapenv:Envelope>


and I POST on the webservice using a simple wget :

wget http://192.168.171.202/docweb/ws/EnvoiDocument --post-file /tmp/soap

Here is the full trace8 log when interrogating the webservice :

[Fri Jun 02 15:12:02.724302 2017] [http2:trace1] [pid 16175] h2_h2.c(591):
[client 192.168.123.4:58944] h2_h2, process_conn
[Fri Jun 02 15:12:02.724361 2017] [http2:trace1] [pid 16175] h2_h2.c(605):
[client 192.168.123.4:58944] h2_h2, process_conn, new connection using protocol
'http/1.1', direct=0, tls acceptable=1
[Fri Jun 02 15:12:02.724370 2017] [http2:trace1] [pid 16175] h2_h2.c(661):
[client 192.168.123.4:58944] h2_h2, declined
[Fri Jun 02 15:12:02.724498 2017] [core:trace5] [pid 16175] protocol.c(645):
[client 192.168.123.4:58944] Request received from client: POST
/docweb/ws/EnvoiDocument HTTP/1.0
[Fri Jun 02 15:12:02.724600 2017] [http:trace4] [pid 16175]
http_request.c(420): [client 192.168.123.4:58944] Headers received from client:
[Fri Jun 02 15:12:02.724604 2017] [http:trace4] [pid 16175]
http_request.c(424): [client 192.168.123.4:58944]   User-Agent: Wget/1.11.4 Red
Hat modified
[Fri Jun 02 15:12:02.724606 2017] [http:trace4] [pid 16175]
http_request.c(424): [client 192.168.123.4:58944]   Accept: */*
[Fri Jun 02 15:12:02.724608 2017] [http:trace4] [pid 16175]
http_request.c(424): [client 192.168.123.4:58944]   Host: 192.168.171.202
[Fri Jun 02 15:12:02.724610 2017] [http:trace4] [pid 16175]
http_request.c(424): [client 192.168.123.4:58944]   Connection: Keep-Alive
[Fri Jun 02 15:12:02.724612 2017] [http:trace4] [pid 16175]
http_request.c(424): [client 192.168.123.4:58944]   Content-Type:
application/x-www-form-urlencoded
[Fri Jun 02 15:12:02.724614 2017] [http:trace4] [pid 16175]
http_request.c(424): [client 192.168.123.4:58944]   Content-Length: 386
[Fri Jun 02 15:12:02.724688 2017] [proxy:trace2] [pid 16175] mod_proxy.c(656):
[client 192.168.123.4:58944] AH03461: attempting to match URI path
'/docweb/ws/EnvoiDocument' against prefix '/' for proxying
[Fri Jun 02 15:12:02.724696 2017] [proxy:trace1] [pid 16175] mod_proxy.c(741):
[client 192.168.123.4:58944] AH03464: URI path '/docweb/ws/EnvoiDocument'
matches proxy handler
'proxy:http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument'
[Fri Jun 02 15:12:02.724723 2017] [authz_core:debug] [pid 16175]
mod_authz_core.c(809): [client 192.168.123.4:58944] AH01626: authorization
result of Require all granted: granted
[Fri Jun 02 15:12:02.724727 2017] [authz_core:debug] [pid 16175]
mod_authz_core.c(809): [client 192.168.123.4:58944] AH01626: authorization
result of <RequireAny>: granted
[Fri Jun 02 15:12:02.724730 2017] [core:trace3] [pid 16175] request.c(293):
[client 192.168.123.4:58944] request authorized without authentication by
access_checker_ex hook: /docweb/ws/EnvoiDocument
[Fri Jun 02 15:12:02.724765 2017] [proxy_http:trace1] [pid 16175]
mod_proxy_http.c(60): [client 192.168.123.4:58944] HTTP: canonicalising URL
//s-docweb-qua-01:8080/docweb/ws/EnvoiDocument
[Fri Jun 02 15:12:02.724813 2017] [proxy:trace2] [pid 16175]
proxy_util.c(1962): [client 192.168.123.4:58944] http: found worker
http://s-docweb-qua-01:8080/ for
http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument
[Fri Jun 02 15:12:02.724818 2017] [proxy:debug] [pid 16175] mod_proxy.c(1228):
[client 192.168.123.4:58944] AH01143: Running scheme http handler (attempt 0)
[Fri Jun 02 15:12:02.724821 2017] [proxy_ajp:debug] [pid 16175]
mod_proxy_ajp.c(738): [client 192.168.123.4:58944] AH00894: declining URL
http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument
[Fri Jun 02 15:12:02.724825 2017] [proxy_fcgi:debug] [pid 16175]
mod_proxy_fcgi.c(913): [client 192.168.123.4:58944] AH01076: url:
http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument proxyname: (null)
proxyport: 0
[Fri Jun 02 15:12:02.724828 2017] [proxy_fcgi:debug] [pid 16175]
mod_proxy_fcgi.c(916): [client 192.168.123.4:58944] AH01077: declining URL
http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument
[Fri Jun 02 15:12:02.724833 2017] [proxy_http:trace1] [pid 16175]
mod_proxy_http.c(1904): [client 192.168.123.4:58944] HTTP: serving URL
http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument
[Fri Jun 02 15:12:02.724837 2017] [proxy:debug] [pid 16175] proxy_util.c(2156):
AH00942: HTTP: has acquired connection for (s-docweb-qua-01)
[Fri Jun 02 15:12:02.724841 2017] [proxy:debug] [pid 16175] proxy_util.c(2209):
[client 192.168.123.4:58944] AH00944: connecting
http://s-docweb-qua-01:8080/docweb/ws/EnvoiDocument to s-docweb-qua-01:8080
[Fri Jun 02 15:12:02.727195 2017] [proxy:debug] [pid 16175] proxy_util.c(2418):
[client 192.168.123.4:58944] AH00947: connected /docweb/ws/EnvoiDocument to
s-docweb-qua-01:8080
[Fri Jun 02 15:12:02.727213 2017] [proxy:trace2] [pid 16175]
proxy_util.c(2850): HTTP: fam 2 socket created to connect to s-docweb-qua-01
[Fri Jun 02 15:12:02.728830 2017] [proxy:debug] [pid 16175] proxy_util.c(2884):
AH02824: HTTP: connection established with 192.168.172.21:8080
(s-docweb-qua-01)
[Fri Jun 02 15:12:02.728847 2017] [proxy:debug] [pid 16175] proxy_util.c(3051):
AH00962: HTTP: connection complete to 192.168.172.21:8080 (s-docweb-qua-01)
[Fri Jun 02 15:12:02.728887 2017] [core:trace6] [pid 16175]
core_filters.c(525): [remote 192.168.172.21:8080] core_output_filter: flushing
because of FLUSH bucket
[Fri Jun 02 15:12:02.731922 2017] [proxy:debug] [pid 16203] proxy_util.c(1779):
AH00925: initializing worker http://s-docweb-qua-01:8080/ shared
[Fri Jun 02 15:12:02.731929 2017] [proxy:debug] [pid 16203] proxy_util.c(1821):
AH00927: initializing worker http://s-docweb-qua-01:8080/ local
[Fri Jun 02 15:12:02.731949 2017] [proxy:debug] [pid 16203] proxy_util.c(1872):
AH00931: initialized single connection worker in child 16203 for
(s-docweb-qua-01)
[Fri Jun 02 15:12:02.764298 2017] [proxy_http:trace3] [pid 16175]
mod_proxy_http.c(1376): [client 192.168.123.4:58944] Status from backend: 200
[Fri Jun 02 15:12:02.764380 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1049): [client 192.168.123.4:58944] Headers received from
backend:
[Fri Jun 02 15:12:02.764393 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1051): [client 192.168.123.4:58944] Connection: keep-alive
[Fri Jun 02 15:12:02.764482 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1051): [client 192.168.123.4:58944] X-Powered-By: xxx
[Fri Jun 02 15:12:02.764495 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1051): [client 192.168.123.4:58944] Server: yyy
[Fri Jun 02 15:12:02.764501 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1051): [client 192.168.123.4:58944] Transfer-Encoding: chunked
[Fri Jun 02 15:12:02.764507 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1051): [client 192.168.123.4:58944] Content-Type:
text/xml;charset=UTF-8
[Fri Jun 02 15:12:02.764512 2017] [proxy_http:trace4] [pid 16175]
mod_proxy_http.c(1051): [client 192.168.123.4:58944] Date: Fri, 02 Jun 2017
13:12:02 GMT
[Fri Jun 02 15:12:02.764539 2017] [proxy_http:trace3] [pid 16175]
mod_proxy_http.c(1647): [client 192.168.123.4:58944] start body send
[Fri Jun 02 15:12:02.764590 2017] [http:trace3] [pid 16175]
http_filters.c(1089): [client 192.168.123.4:58944] Response sent with status
200, headers:
[Fri Jun 02 15:12:02.764594 2017] [http:trace5] [pid 16175]
http_filters.c(1096): [client 192.168.123.4:58944]   Date: Fri, 02 Jun 2017
13:12:02 GMT
[Fri Jun 02 15:12:02.764595 2017] [http:trace5] [pid 16175]
http_filters.c(1099): [client 192.168.123.4:58944]   Server: yyy
[Fri Jun 02 15:12:02.764598 2017] [http:trace4] [pid 16175]
http_filters.c(918): [client 192.168.123.4:58944]   X-Powered-By: xxx
[Fri Jun 02 15:12:02.764601 2017] [http:trace4] [pid 16175]
http_filters.c(918): [client 192.168.123.4:58944]   Content-Type:
text/xml;charset=UTF-8
[Fri Jun 02 15:12:02.764602 2017] [http:trace4] [pid 16175]
http_filters.c(918): [client 192.168.123.4:58944]   Connection: close
[Fri Jun 02 15:12:02.764643 2017] [core:trace6] [pid 16175]
core_filters.c(525): [client 192.168.123.4:58944] core_output_filter: flushing
because of FLUSH bucket
[Fri Jun 02 15:12:02.765745 2017] [core:trace6] [pid 16175]
core_filters.c(525): [client 192.168.123.4:58944] core_output_filter: flushing
because of FLUSH bucket
[Fri Jun 02 15:12:02.765863 2017] [core:trace6] [pid 16175]
core_filters.c(525): [client 192.168.123.4:58944] core_output_filter: flushing
because of FLUSH bucket
[Fri Jun 02 15:12:02.767527 2017] [proxy_http:error] [pid 16175] (70008)Partial
results are valid but processing is incomplete: [client 192.168.123.4:58944]
AH01110: error reading response
[Fri Jun 02 15:12:02.767557 2017] [proxy_http:trace2] [pid 16175]
mod_proxy_http.c(1792): [client 192.168.123.4:58944] end body send
[Fri Jun 02 15:12:02.767564 2017] [proxy:debug] [pid 16175] proxy_util.c(2171):
AH00943: HTTP: has released connection for (s-docweb-qua-01)
[Fri Jun 02 15:12:02.767698 2017] [core:trace6] [pid 16175]
core_filters.c(525): [client 192.168.123.4:58944] core_output_filter: flushing
because of FLUSH bucket
[Fri Jun 02 15:12:02.767704 2017] [core:trace6] [pid 16175]
core_filters.c(525): [client 192.168.123.4:58944] core_output_filter: flushing
because of FLUSH bucket

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@xxxxxxxxxxxxxxxx
For additional commands, e-mail: bugs-help@xxxxxxxxxxxxxxxx