Welcome! Log In Create A New Profile

Advanced

HTTP Basic Authorisation requests failing with HAProxy 1.7.2

Posted by Jon Simpson 
Jon Simpson
HTTP Basic Authorisation requests failing with HAProxy 1.7.2
February 21, 2017 07:40PM
Hi all,

We’re experiencing a problem with clients receiving 503 responses when
making a request to a backend with a Authorisation header set (basic
authentication) using HAProxy 1.7.2. We didn't experience this with HAProxy
1.6.11.

The HAProxy stats page shows that the backends in question have no downtime
(what I would usually expect to see in cases where 503 statuses are
returned). Only certain clients are affected by this behaviour - a number
have been completely unaffected. The behaviour we're seeing shares some
similarities to one that reported in 1.7.1 (
https:[email protected]/msg24613.html) but we're
not seeing any useful output from show errors and the code is 503. We do
know that packet reordering/retranmission is happening in at least one case..

Our clients can retry these requests and occasionally get them to succeed.
Additionally, they found putting delays between the post of data and close
of the connection did lead to successes in making the connection. We're
sure HAProxy is the source of our client's 503 errors as the clients are
getting the text of our custom 503 page (rather than a 503 from the IIS
service behind).

For context - we have an ELB in TCP-only mode in front of the HAProxy (to
distribute connections across multiple HAProxy instances) if that's
relevant. We're using the latest HAProxy 1.7 Ubuntu PPA's (
https://launchpad.net/~vbernat/+archive/ubuntu/haproxy-1.7). Logging is
enabled, with the following format string (we capture the Host request
header with a len of 64 for +Q) -

log-format %ci:%cp\ [%t]\ %ft\ %b/%s\ %Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\
%CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID

but we don't appear to be seeing the requests that are receiving 503
responses being logged. We do use 'option dontlognull' as these HAProxy
instances are behind ELB, and hence get checked for TCP liveness but as
these are valid HTTPS requests being returned 503 I would expect them to be
in our main haproxy log.

I'd really appreciate any input you could give on further triage steps
(especially being able to identify in log when clients are receiving 503
responses) or potential causes we can look at.

Thanks,
Jon
Hi all,

Further to my previous message to the list I can now reliably reproduce the
behaviour where certain requests using authentication headers receive 503
responses from HAProxy 1.7.3.

We’re making a request twice, once without basic auth (checking that basic
auth is prompted on the URL) and then a second, identical, request but with
the the basic auth Authorization header set. The request body is textual
file content, so these requests are larger than average GET/POST requests
(Content-Length > 3500). We don't see this problem with smaller requests.

The two requests happen on a single connection to HAProxy as we have
keepalive enabled. The first request is always sent to the backend
successfully and but the second request receives a 503 status from HAProxy
whenever the request size is over a Content-Length of 3500. Just below this
size the 503’s are sporadic and at very small body sizes it doesn’t happen
at all - the request is sent to the backend succesfully.

There are no errors visible by catting the stats socket, and the second
request/503 response is not present in logs at all (using option httplog).

We don't get this behaviour when keeping all other variables the same
(client, request body & HAProxy configuration) using HAProxy 1.6.11.

Thanks in advance for any help anyone can provide.

Jon

Relevant parts of a client log. Our app server runs IIS/8.5, the 503
Service Unavailable is from our HAProxy 503 template.

2017/03/02 12:14:02:133 UTC [DEBUG] DefaultHttpClient - Attempt 1 to
execute request
2017/03/02 12:14:02:133 UTC [DEBUG] DefaultClientConnection - Sending
request: POST /v1/expost/check HTTP/1.1
2017/03/02 12:14:02:134 UTC [DEBUG] wire - >> "POST /v1/expost/check
HTTP/1.1[\r][\n]"
2017/03/02 12:14:02:134 UTC [DEBUG] wire - >> "Content-Length: 3634[\r][\n]"
2017/03/02 12:14:02:151 UTC [DEBUG] wire - << "HTTP/1.1 401
Unauthorized[\r][\n]"
2017/03/02 12:14:02:152 UTC [DEBUG] wire - << "Server:
Microsoft-IIS/8.5[\r][\n]”

2017/03/02 12:14:02:157 UTC [DEBUG] DefaultHttpClient - Connection can be
kept alive indefinitely

2017/03/02 12:14:02:158 UTC [DEBUG] DefaultHttpClient - Authentication
required
2017/03/02 12:14:02:159 UTC [DEBUG] DefaultHttpClient - XXX:443 requested
authentication
2017/03/02 12:14:02:170 UTC [DEBUG] RequestTargetAuthentication - Target
auth state: CHALLENGED
2017/03/02 12:14:02:171 UTC [DEBUG] RequestTargetAuthentication -
Generating response to an authentication challenge using basic scheme
2017/03/02 12:14:02:179 UTC [DEBUG] DefaultHttpClient - Attempt 2 to
execute request
2017/03/02 12:14:02:179 UTC [DEBUG] DefaultClientConnection - Sending
request: POST /v1/expost/check HTTP/1.1
2017/03/02 12:14:02:179 UTC [DEBUG] wire - >> "POST /v1/expost/check
HTTP/1.1[\r][\n]"
2017/03/02 12:14:02:182 UTC [DEBUG] wire - >> "Content-Length: 3634[\r][\n]"
2017/03/02 12:14:02:196 UTC [DEBUG] wire - << "HTTP/1.0 503 Service
Unavailable[\r][\n]"
2017/03/02 12:14:02:196 UTC [DEBUG] wire - << "Cache-Control:
no-cache[\r][\n]"
2017/03/02 12:14:02:196 UTC [DEBUG] wire - << "Connection: close[\r][\n]"

On 21 February 2017 at 18:36:21, Jon Simpson ([email protected]) wrote:

Hi all,

We’re experiencing a problem with clients receiving 503 responses when
making a request to a backend with a Authorisation header set (basic
authentication) using HAProxy 1.7.2. We didn't experience this with HAProxy
1.6.11.

The HAProxy stats page shows that the backends in question have no downtime
(what I would usually expect to see in cases where 503 statuses are
returned). Only certain clients are affected by this behaviour - a number
have been completely unaffected. The behaviour we're seeing shares some
similarities to one that reported in 1.7.1 (
https:[email protected]/msg24613.html) but we're
not seeing any useful output from show errors and the code is 503. We do
know that packet reordering/retranmission is happening in at least one case..

Our clients can retry these requests and occasionally get them to succeed.
Additionally, they found putting delays between the post of data and close
of the connection did lead to successes in making the connection. We're
sure HAProxy is the source of our client's 503 errors as the clients are
getting the text of our custom 503 page (rather than a 503 from the IIS
service behind).

For context - we have an ELB in TCP-only mode in front of the HAProxy (to
distribute connections across multiple HAProxy instances) if that's
relevant. We're using the latest HAProxy 1.7 Ubuntu PPA's (
https://launchpad.net/~vbernat/+archive/ubuntu/haproxy-1.7). Logging is
enabled, with the following format string (we capture the Host request
header with a len of 64 for +Q) -

log-format %ci:%cp\ [%t]\ %ft\ %b/%s\ %Tq/%Tw/%Tc/%Tr/%Tt\ %ST\ %B\ %CC\
%CS\ %tsc\ %ac/%fc/%bc/%sc/%rc\ %sq/%bq\ %hr\ %hs\ %{+Q}r\ %ID

but we don't appear to be seeing the requests that are receiving 503
responses being logged. We do use 'option dontlognull' as these HAProxy
instances are behind ELB, and hence get checked for TCP liveness but as
these are valid HTTPS requests being returned 503 I would expect them to be
in our main haproxy log.

I'd really appreciate any input you could give on further triage steps
(especially being able to identify in log when clients are receiving 503
responses) or potential causes we can look at.

Thanks,
Jon
Christopher Faulet
Re: HTTP Basic Authorisation requests failing with HAProxy 1.7.2
March 02, 2017 10:00PM
Le 02/03/2017 à 16:46, Jon Simpson a écrit :
> Hi all,
>
> Further to my previous message to the list I can now reliably reproduce
> the behaviour where certain requests using authentication headers
> receive 503 responses from HAProxy 1.7.3.
>
> We’re making a request twice, once without basic auth (checking that
> basic auth is prompted on the URL) and then a second, identical, request
> but with the the basic auth Authorization header set. The request body
> is textual file content, so these requests are larger than average
> GET/POST requests (Content-Length > 3500). We don't see this problem
> with smaller requests.
>
> The two requests happen on a single connection to HAProxy as we have
> keepalive enabled. The first request is always sent to the backend
> successfully and but the second request receives a 503 status from
> HAProxy whenever the request size is over a Content-Length of 3500. Just
> below this size the 503’s are sporadic and at very small body sizes it
> doesn’t happen at all - the request is sent to the backend succesfully.
>
> There are no errors visible by catting the stats socket, and the second
> request/503 response is not present in logs at all (using option httplog).
>
> We don't get this behaviour when keeping all other variables the same
> (client, request body & HAProxy configuration) using HAProxy 1.6.11.
>
> Thanks in advance for any help anyone can provide.

Hi,

I've quickly tried to reproduce your bug without success. Please, share
you configuration to be sure to do test in the same situation.

It could also be helpful to have a tcpdump for data exchanged between
your client and HAProxy and another one for data exchanged between
HAProxy and your webserver.

If you cannot do a tcpdump, you can use the trace filter by adding the
following line in your frontend/listener section:

filer trace

Then run HAProxy in foreground.

--
Christopher Faulet
On 2 March 2017 at 20:56:37, Christopher Faulet ([email protected]) wrote:

Le 02/03/2017 à 16:46, Jon Simpson a écrit :
> Hi all,
>
> Further to my previous message to the list I can now reliably reproduce
> the behaviour where certain requests using authentication headers
> receive 503 responses from HAProxy 1.7.3.
>
> We’re making a request twice, once without basic auth (checking that
> basic auth is prompted on the URL) and then a second, identical, request
> but with the the basic auth Authorization header set. The request body
> is textual file content, so these requests are larger than average
> GET/POST requests (Content-Length > 3500). We don't see this problem
> with smaller requests.
>
> The two requests happen on a single connection to HAProxy as we have
> keepalive enabled. The first request is always sent to the backend
> successfully and but the second request receives a 503 status from
> HAProxy whenever the request size is over a Content-Length of 3500. Just
> below this size the 503’s are sporadic and at very small body sizes it
> doesn’t happen at all - the request is sent to the backend succesfully.
>
> There are no errors visible by catting the stats socket, and the second
> request/503 response is not present in logs at all (using option httplog)..

>
> We don't get this behaviour when keeping all other variables the same
> (client, request body & HAProxy configuration) using HAProxy 1.6.11.
>
> Thanks in advance for any help anyone can provide.

Hi,

I've quickly tried to reproduce your bug without success. Please, share
you configuration to be sure to do test in the same situation.

It could also be helpful to have a tcpdump for data exchanged between
your client and HAProxy and another one for data exchanged between
HAProxy and your webserver.

If you cannot do a tcpdump, you can use the trace filter by adding the
following line in your frontend/listener section:

filer trace

Then run HAProxy in foreground.

--
Christopher Faulet

Hi Christopher,
Thanks for your response. I’ve attached the requested configuration and
HAProxy trace logs below (TCPdump appeared to be much noisier). I have an
input file which reproduces the 503 case but not predictably, so I’ve
included one log which generated the correct 401 response from HAProxy and
one which returned a 503 response. The 503 response comes back every time
with larger requests than this. I’ve stripped down the configuration to a
minimum which reproduces the issue.

The behaviour only seems to occur with proxy-protocol enabled
(accept-proxy). I initially tested directly sending requests directly to
HAProxy and that works without the 503 responses. We run this HAProxy
configuration behind Amazon ELB - a TCP load balancer with proxy protocol
enabled, where the issue occurs (and it occurred in my test environment
once proxy protocol was enabled and connections went through the TCP load
balancer).

Thanks,
Jon
1488550830.939713 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00000000 0x00000000] trace_attach : filter-type=frontend
1488550830.939713 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00000000 0x00000000] trace_stream_start
00000006:https-in.accept(0005)=0008 from [34.250.167.137:38280]
1488550830.939713 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034035 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550830.939713 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
00000006:https-in.clireq[0008:ffffffff]: POST /v1/expost/check HTTP/1.1
00000006:https-in.clihdr[0008:ffffffff]: Content-Length: 3632
00000006:https-in.clihdr[0008:ffffffff]: Content-Type: application/xml
00000006:https-in.clihdr[0008:ffffffff]: Host: [REDACTED]
00000006:https-in.clihdr[0008:ffffffff]: Connection: Keep-Alive
00000006:https-in.clihdr[0008:ffffffff]: User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034030 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=POST
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034030 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_HTTP_PROCESS_FE - step=PRE
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034020 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_HTTP_PROCESS_FE - step=POST
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034020 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_SWITCHING_RULES - step=PRE
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00034000 0x00000000] trace_attach : filter-type=backend
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034000 0x00000000] trace_stream_set_backend : backend=web-02
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00034000 0x00000000] trace_stream_set_backend : backend=web-02
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034940 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_SWITCHING_RULES - step=POST
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00034940 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (backend)
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034900 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=PRE
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00034900 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=PRE
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=POST
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=POST
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=PRE
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=PRE
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=POST
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=POST
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] trace_http_headers : channel=REQUEST - mode=HTTP (backend)
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] POST /v1/expost/check HTTP/1.1
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] Content-Length: 3632
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] Content-Type: application/xml
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] Host: [REDACTED]
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] X-Forwarded-For: 34.250.167.137
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] trace_http_headers : channel=REQUEST - mode=HTTP (backend)
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] POST /v1/expost/check HTTP/1.1
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] Content-Length: 3632
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] Content-Type: application/xml
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] Host: [REDACTED]
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x0002c000 0x00000000] X-Forwarded-For: 34.250.167.137
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=194 - fwd=0 - avail=0 - consume=0
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=194 - fwd=0 - avail=0 - consume=0
1488550830.976938 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=194 - nxt=194 - fwd=0 - forward=194
1488550830.976938 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=194 - nxt=194 - fwd=0 - forward=194
1488550830.981614 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=3632 - consume=3632
1488550830.981614 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=3632 - consume=3632
1488550830.981614 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=3632 - nxt=3632 - fwd=0 - forward=3632
1488550830.981614 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=3632 - nxt=3632 - fwd=0 - forward=3632
1488550830.981614 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_end : channel=REQUEST - mode=HTTP (backend)
1488550830.981614 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x00000000] trace_http_end : channel=REQUEST - mode=HTTP (backend)
1488550830.982432 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0dac0000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550830.982432 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0dac0000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550830.982432 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0da80000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550830.982432 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550830.982432 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
00000006:web-02.srvrep[0008:0009]: HTTP/1.1 401 Unauthorized
00000006:web-02.srvhdr[0008:0009]: Server: Microsoft-IIS/8.5
00000006:web-02.srvhdr[0008:0009]: WWW-Authenticate: Basic realm=FundApps API
00000006:web-02.srvhdr[0008:0009]: X-Powered-By: ASP.NET
00000006:web-02.srvhdr[0008:0009]: X-FA-Server: WEB-02A
00000006:web-02.srvhdr[0008:0009]: Date: Fri, 03 Mar 2017 14:20:28 GMT
00000006:web-02.srvhdr[0008:0009]: Content-Length: 0
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=POST
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=POST
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=PRE
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=PRE
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=POST
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=POST
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] trace_http_headers : channel=RESPONSE - mode=HTTP (backend)
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] HTTP/1.1 401 Unauthorized
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] Server: Microsoft-IIS/8.5
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] WWW-Authenticate: Basic realm=FundApps API
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] X-Powered-By: ASP.NET
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] X-FA-Server: WEB-02A
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] Date: Fri, 03 Mar 2017 14:20:28 GMT
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] Content-Length: 0
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] trace_http_headers : channel=RESPONSE - mode=HTTP (backend)
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] HTTP/1.1 401 Unauthorized
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] Server: Microsoft-IIS/8.5
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] WWW-Authenticate: Basic realm=FundApps API
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] X-Powered-By: ASP.NET
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] X-FA-Server: WEB-02A
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] Date: Fri, 03 Mar 2017 14:20:28 GMT
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0b000000] Content-Length: 0
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0a000000] trace_http_data : channel=RESPONSE - mode=HTTP (backend) - chunk_len=0 - next=201 - fwd=0 - avail=0 - consume=0
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0a000000] trace_http_data : channel=RESPONSE - mode=HTTP (backend) - chunk_len=0 - next=201 - fwd=0 - avail=0 - consume=0
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0a000000] trace_http_forward_data : channel=RESPONSE - mode=HTTP (backend) - len=201 - nxt=201 - fwd=0 - forward=201
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0a000000] trace_http_forward_data : channel=RESPONSE - mode=HTTP (backend) - len=201 - nxt=201 - fwd=0 - forward=201
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(6) 0x00028000 0x0a000000] trace_http_end : channel=RESPONSE - mode=HTTP (backend)
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(6) 0x00028000 0x0a000000] trace_http_end : channel=RESPONSE - mode=HTTP (backend)
1488550830.983488 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00020000 0x08000000] trace_chn_end_analyze : channel=RESPONSE - mode=HTTP (frontend)
1488550830.983488 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00020000 0x08000000] trace_chn_end_analyze : channel=RESPONSE - mode=HTTP (frontend)
1488550830.985684 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00020000 0x00000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550830.985684 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00020000 0x00000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550830.985684 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034035 0x00000000] trace_detach : filter-type=backend
1488550830.985684 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034035 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550830.985684 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
00000007:https-in.clireq[0008:0009]: POST /v1/expost/check HTTP/1.1
00000007:https-in.clihdr[0008:0009]: Content-Length: 3632
00000007:https-in.clihdr[0008:0009]: Content-Type: application/xml
00000007:https-in.clihdr[0008:0009]: Host: [REDACTED]
00000007:https-in.clihdr[0008:0009]: Connection: Keep-Alive
00000007:https-in.clihdr[0008:0009]: User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
00000007:https-in.clihdr[0008:0009]: Authorization: Basic dGVzdDp0ZXN0
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034030 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=POST
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034030 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_HTTP_PROCESS_FE - step=PRE
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034020 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_HTTP_PROCESS_FE - step=POST
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034020 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_SWITCHING_RULES - step=PRE
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034000 0x00000000] trace_attach : filter-type=backend
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034000 0x00000000] trace_stream_set_backend : backend=web-02
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034000 0x00000000] trace_stream_set_backend : backend=web-02
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034940 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_SWITCHING_RULES - step=POST
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034940 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (backend)
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034900 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=PRE
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034900 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=PRE
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=POST
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=POST
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=PRE
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=PRE
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=POST
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=POST
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] trace_http_headers : channel=REQUEST - mode=HTTP (backend)
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] POST /v1/expost/check HTTP/1.1
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Content-Length: 3632
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Content-Type: application/xml
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Host: [REDACTED]
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Authorization: Basic dGVzdDp0ZXN0
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] X-Forwarded-For: 34.250.167.137
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] trace_http_headers : channel=REQUEST - mode=HTTP (backend)
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] POST /v1/expost/check HTTP/1.1
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Content-Length: 3632
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Content-Type: application/xml
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Host: [REDACTED]
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] Authorization: Basic dGVzdDp0ZXN0
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x0002c000 0x00000000] X-Forwarded-For: 34.250.167.137
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=229 - fwd=0 - avail=0 - consume=0
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=229 - fwd=0 - avail=0 - consume=0
1488550831.022211 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=229 - nxt=229 - fwd=0 - forward=229
1488550831.022211 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=229 - nxt=229 - fwd=0 - forward=229
1488550831.026857 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=3632 - consume=3632
1488550831.026857 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=3632 - consume=3632
1488550831.026857 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=3632 - nxt=3632 - fwd=0 - forward=3632
1488550831.026857 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=3632 - nxt=3632 - fwd=0 - forward=3632
1488550831.026857 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_http_end : channel=REQUEST - mode=HTTP (backend)
1488550831.026857 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_http_end : channel=REQUEST - mode=HTTP (backend)
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0dac0000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0da80000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
00000007:web-02.srvrep[0008:0009]: HTTP/1.1 401 Unauthorized
00000007:web-02.srvhdr[0008:0009]: Server: Microsoft-IIS/8.5
00000007:web-02.srvhdr[0008:0009]: WWW-Authenticate: Basic realm=FundApps API
00000007:web-02.srvhdr[0008:0009]: X-Powered-By: ASP.NET
00000007:web-02.srvhdr[0008:0009]: X-FA-Server: WEB-02A
00000007:web-02.srvhdr[0008:0009]: Date: Fri, 03 Mar 2017 14:20:28 GMT
00000007:web-02.srvhdr[0008:0009]: Content-Length: 0
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=POST
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=POST
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=PRE
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=PRE
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=POST
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=POST
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] trace_http_headers : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] HTTP/1.1 401 Unauthorized
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] Server: Microsoft-IIS/8.5
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] WWW-Authenticate: Basic realm=FundApps API
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] X-Powered-By: ASP.NET
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] X-FA-Server: WEB-02A
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] Date: Fri, 03 Mar 2017 14:20:28 GMT
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] Content-Length: 0
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] trace_http_headers : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] HTTP/1.1 401 Unauthorized
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] Server: Microsoft-IIS/8.5
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] WWW-Authenticate: Basic realm=FundApps API
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] X-Powered-By: ASP.NET
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] X-FA-Server: WEB-02A
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] Date: Fri, 03 Mar 2017 14:20:28 GMT
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0b000000] Content-Length: 0
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0a000000] trace_http_data : channel=RESPONSE - mode=HTTP (backend) - chunk_len=0 - next=201 - fwd=0 - avail=0 - consume=0
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0a000000] trace_http_data : channel=RESPONSE - mode=HTTP (backend) - chunk_len=0 - next=201 - fwd=0 - avail=0 - consume=0
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0a000000] trace_http_forward_data : channel=RESPONSE - mode=HTTP (backend) - len=201 - nxt=201 - fwd=0 - forward=201
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0a000000] trace_http_forward_data : channel=RESPONSE - mode=HTTP (backend) - len=201 - nxt=201 - fwd=0 - forward=201
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(7) 0x00028000 0x0a000000] trace_http_end : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(7) 0x00028000 0x0a000000] trace_http_end : channel=RESPONSE - mode=HTTP (backend)
1488550831.033378 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00020000 0x08000000] trace_chn_end_analyze : channel=RESPONSE - mode=HTTP (frontend)
1488550831.033378 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(8) 0x00020000 0x08000000] trace_chn_end_analyze : channel=RESPONSE - mode=HTTP (frontend)
1488550831.035268 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00020000 0x00000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550831.035268 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(8) 0x00020000 0x00000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550831.035268 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(8) 0x00034035 0x00000000] trace_detach : filter-type=backend
1488550831.035268 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00034035 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550831.035268 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
1488550831.056425 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
1488550831.056425 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00020000 0x00000000] trace_http_reply : channel=- - mode=HTTP (frontend)
1488550831.056425 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00020000 0x00000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
00000008:https-in.clicls[0008:0009]
00000008:https-in.closed[0008:0009]
1488550831.056425 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00000000 0x00000000] trace_stream_stop
1488550831.056425 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(8) 0x00000000 0x00000000] trace_detach : filter-type=frontend
1488550869.455670 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00000000 0x00000000] trace_attach : filter-type=frontend
1488550869.455670 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00000000 0x00000000] trace_stream_start
0000000e:https-in.accept(0005)=0008 from [34.250.167.137:38284]
1488550869.455670 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034035 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550869.455670 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
0000000e:https-in.clireq[0008:ffffffff]: POST /v1/expost/check HTTP/1.1
0000000e:https-in.clihdr[0008:ffffffff]: Content-Length: 3632
0000000e:https-in.clihdr[0008:ffffffff]: Content-Type: application/xml
0000000e:https-in.clihdr[0008:ffffffff]: Host: [REDACTED]
0000000e:https-in.clihdr[0008:ffffffff]: Connection: Keep-Alive
0000000e:https-in.clihdr[0008:ffffffff]: User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034030 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=POST
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034030 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_HTTP_PROCESS_FE - step=PRE
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034020 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_HTTP_PROCESS_FE - step=POST
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034020 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_SWITCHING_RULES - step=PRE
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00034000 0x00000000] trace_attach : filter-type=backend
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034000 0x00000000] trace_stream_set_backend : backend=web-02
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00034000 0x00000000] trace_stream_set_backend : backend=web-02
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034940 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_SWITCHING_RULES - step=POST
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00034940 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (backend)
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034900 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=PRE
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00034900 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=PRE
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=POST
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_PROCESS_BE - step=POST
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=PRE
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00034800 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=PRE
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=POST
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (backend) - analyzer=AN_REQ_HTTP_INNER - step=POST
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] trace_http_headers : channel=REQUEST - mode=HTTP (backend)
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] POST /v1/expost/check HTTP/1.1
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] Content-Length: 3632
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] Content-Type: application/xml
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] Host: [REDACTED]
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] X-Forwarded-For: 34.250.167.137
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] trace_http_headers : channel=REQUEST - mode=HTTP (backend)
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] POST /v1/expost/check HTTP/1.1
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] Content-Length: 3632
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] Content-Type: application/xml
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] Host: [REDACTED]
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] User-Agent: Apache-HttpClient/4.2.3 (java 1.5)
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x0002c000 0x00000000] X-Forwarded-For: 34.250.167.137
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=194 - fwd=0 - avail=0 - consume=0
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x00000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=194 - fwd=0 - avail=0 - consume=0
1488550869.491238 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=194 - nxt=194 - fwd=0 - forward=194
1488550869.491238 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x00000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=194 - nxt=194 - fwd=0 - forward=194
1488550869.491958 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0dac0000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=0 - consume=0
1488550869.491958 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0dac0000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=0 - consume=0
1488550869.491958 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0dac0000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=0 - nxt=0 - fwd=0 - forward=0
1488550869.491958 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0dac0000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=0 - nxt=0 - fwd=0 - forward=0
1488550869.491958 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0dac0000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550869.491958 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0dac0000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550869.491958 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0da80000] trace_chn_start_analyze : channel=RESPONSE - mode=HTTP (backend)
1488550869.491958 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550869.491958 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0da00000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=PRE
0000000e:web-02.srvrep[0008:0009]: HTTP/1.1 401 Unauthorized
0000000e:web-02.srvhdr[0008:0009]: Server: Microsoft-IIS/8.5
0000000e:web-02.srvhdr[0008:0009]: WWW-Authenticate: Basic realm=FundApps API
0000000e:web-02.srvhdr[0008:0009]: X-Powered-By: ASP.NET
0000000e:web-02.srvhdr[0008:0009]: X-FA-Server: WEB-02A
0000000e:web-02.srvhdr[0008:0009]: Date: Fri, 03 Mar 2017 14:21:06 GMT
0000000e:web-02.srvhdr[0008:0009]: Content-Length: 0
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=POST
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_WAIT_HTTP - step=POST
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=PRE
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0d800000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=PRE
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=POST
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] trace_chn_analyze : channel=RESPONSE - mode=HTTP (backend) - analyzer=AN_RES_HTTP_PROCESS_FE/BE - step=POST
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] trace_http_headers : channel=RESPONSE - mode=HTTP (backend)
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] HTTP/1.1 401 Unauthorized
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] Server: Microsoft-IIS/8.5
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] WWW-Authenticate: Basic realm=FundApps API
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] X-Powered-By: ASP.NET
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] X-FA-Server: WEB-02A
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] Date: Fri, 03 Mar 2017 14:21:06 GMT
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] Content-Length: 0
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] trace_http_headers : channel=RESPONSE - mode=HTTP (backend)
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] HTTP/1.1 401 Unauthorized
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] Server: Microsoft-IIS/8.5
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] WWW-Authenticate: Basic realm=FundApps API
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] X-Powered-By: ASP.NET
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] X-FA-Server: WEB-02A
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] Date: Fri, 03 Mar 2017 14:21:06 GMT
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0b000000] Content-Length: 0
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_data : channel=RESPONSE - mode=HTTP (backend) - chunk_len=0 - next=201 - fwd=0 - avail=0 - consume=0
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_data : channel=RESPONSE - mode=HTTP (backend) - chunk_len=0 - next=201 - fwd=0 - avail=0 - consume=0
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_forward_data : channel=RESPONSE - mode=HTTP (backend) - len=201 - nxt=201 - fwd=0 - forward=201
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_forward_data : channel=RESPONSE - mode=HTTP (backend) - len=201 - nxt=201 - fwd=0 - forward=201
1488550869.492754 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_end : channel=RESPONSE - mode=HTTP (backend)
1488550869.492754 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_end : channel=RESPONSE - mode=HTTP (backend)
1488550869.494912 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=3632 - consume=3632
1488550869.494912 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_data : channel=REQUEST - mode=HTTP (backend) - chunk_len=3632 - next=0 - fwd=0 - avail=3632 - consume=3632
1488550869.494912 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=3632 - nxt=3632 - fwd=0 - forward=3632
1488550869.494912 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_forward_data : channel=REQUEST - mode=HTTP (backend) - len=3632 - nxt=3632 - fwd=0 - forward=3632
1488550869.494912 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_end : channel=REQUEST - mode=HTTP (backend)
1488550869.494912 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(e) 0x00028000 0x0a000000] trace_http_end : channel=REQUEST - mode=HTTP (backend)
1488550869.495170 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00020000 0x08000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550869.495170 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(f) 0x00020000 0x08000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550869.495170 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00000000 0x08000000] trace_http_reply : channel=- - mode=HTTP (frontend)
1488550869.495170 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(f) 0x00000000 0x08000000] trace_http_reply : channel=- - mode=HTTP (frontend)
1488550869.495170 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00000000 0x08000000] trace_chn_end_analyze : channel=RESPONSE - mode=HTTP (frontend)
1488550869.495170 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(f) 0x00000000 0x08000000] trace_chn_end_analyze : channel=RESPONSE - mode=HTTP (frontend)
1488550869.495170 [BE-BEFORE-COMP/web-02] [strm 0x55ec556ab060(f) 0x00034035 0x00000000] trace_detach : filter-type=backend
1488550869.495170 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00034035 0x00000000] trace_chn_start_analyze : channel=REQUEST - mode=HTTP (frontend)
1488550869.495170 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00034034 0x00000000] trace_chn_analyze : channel=REQUEST - mode=HTTP (frontend) - analyzer=AN_REQ_WAIT_HTTP - step=PRE
1488550869.495170 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00020000 0x00000000] trace_http_reply : channel=- - mode=HTTP (frontend)
1488550869.495514 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00020000 0x00000000] trace_chn_end_analyze : channel=REQUEST - mode=HTTP (frontend)
0000000f:https-in.clicls[0008:0009]
0000000f:https-in.closed[0008:0009]
1488550869.495514 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00000000 0x00000000] trace_stream_stop
1488550869.495514 [FE-BEFORE-COMP/https-in] [strm 0x55ec556ab060(f) 0x00000000 0x00000000] trace_detach : filter-type=frontend
Attachments:
open | download - repro-haproxy.cfg (1.6 KB)
Christopher Faulet
Re: HTTP Basic Authorisation requests failing with HAProxy 1.7.2
March 07, 2017 10:00AM
Le 03/03/2017 à 15:44, Jon Simpson a écrit :
>
> Thanks for your response. I’ve attached the requested configuration and
> HAProxy trace logs below (TCPdump appeared to be much noisier). I have
> an input file which reproduces the 503 case but not predictably, so I’ve
> included one log which generated the correct 401 response from HAProxy
> and one which returned a 503 response. The 503 response comes back every
> time with larger requests than this. I’ve stripped down the
> configuration to a minimum which reproduces the issue.
>
> The behaviour only seems to occur with proxy-protocol enabled
> (accept-proxy). I initially tested directly sending requests directly to
> HAProxy and that works without the 503 responses. We run this HAProxy
> configuration behind Amazon ELB - a TCP load balancer with proxy
> protocol enabled, where the issue occurs (and it occurred in my test
> environment once proxy protocol was enabled and connections went through
> the TCP load balancer).
>

Hi Jon,

Thanks for these info. By checking how you named your trace filters, I
guess you use the HTTP compression. If I'm right, I think I found a bug
with the help of your logs.

The bug is triggered when your HTTP server replies before the end of the
request. I guess it always sends its 401 responses just after reading
requests headers. So it is timing issue from the HAProxy point of view.
This should work of course. If I'm right, the bug only appears when a
filter is used. So a temporary workaround, waiting my fix, is to disable
the HTTP compression.

I'll try to fix it very soon, I just need to talk with Willy to do it
the right way. I will keep you informed.

--
Christopher Faulet
On 7 March 2017 at 08:48:37, Christopher Faulet ([email protected]) wrote:

Thanks for these info. By checking how you named your trace filters, I
guess you use the HTTP compression. If I'm right, I think I found a bug
with the help of your logs.

The bug is triggered when your HTTP server replies before the end of the
request. I guess it always sends its 401 responses just after reading
requests headers. So it is timing issue from the HAProxy point of view.
This should work of course. If I'm right, the bug only appears when a
filter is used. So a temporary workaround, waiting my fix, is to disable
the HTTP compression.

I'll try to fix it very soon, I just need to talk with Willy to do it
the right way. I will keep you informed.

--
Christopher Faulet

Hi Christopher,

Yes - you’re right, in our normal configuration the compression filter is
enabled.

I was able to continue replicating the issue even without the compression
filter when testing/generating those logs, but that was with the trace
filter enabled - so there was always a filter. When I remove all filters
(both trace & compression) the issue doesn’t reproduce in my test
environment any more, so I think your theory is correct.

Thanks for tracking it down - much appreciated :)

Jon
Christopher Faulet
Re: HTTP Basic Authorisation requests failing with HAProxy 1.7.2
March 10, 2017 09:50PM
Le 07/03/2017 à 20:51, Jon Simpson a écrit :
> On 7 March 2017 at 08:48:37, Christopher Faulet ([email protected]
> <mailto:[email protected]>) wrote:
>> Thanks for these info. By checking how you named your trace filters, I
>> guess you use the HTTP compression. If I'm right, I think I found a bug
>> with the help of your logs.
>>
>> The bug is triggered when your HTTP server replies before the end of the
>> request. I guess it always sends its 401 responses just after reading
>> requests headers. So it is timing issue from the HAProxy point of view.
>> This should work of course. If I'm right, the bug only appears when a
>> filter is used. So a temporary workaround, waiting my fix, is to disable
>> the HTTP compression.
>>
>> I'll try to fix it very soon, I just need to talk with Willy to do it
>> the right way. I will keep you informed.
>>
>> --
>> Christopher Faulet
>
> Hi Christopher,
>
> Yes - you’re right, in our normal configuration the compression filter
> is enabled.
>
> I was able to continue replicating the issue even without the
> compression filter when testing/generating those logs, but that was with
> the trace filter enabled - so there was always a filter. When I remove
> all filters (both trace & compression) the issue doesn’t reproduce in my
> test environment any more, so I think your theory is correct.
>
> Thanks for tracking it down - much appreciated :)
>

Hi Jon,

Here is a patch that should fix your bug. It was trickier than expected.
Could you confirm that it fix your bug ?

--
Christopher Faulet
On 10 March 2017 at 20:40:11, Christopher Faulet ([email protected])
wrote:

Hi Jon,

Here is a patch that should fix your bug. It was trickier than expected.
Could you confirm that it fix your bug ?

--
Christopher Faulet

Hi Christopher,

The patch does seem to fix the bug in my testing - I can’t reproduce the
503 errors with your patch on 1.8. Sorry for taking a few days to get
around to looking at this & thanks for the fix!

Jon
Hi Jon,

On Wed, Mar 15, 2017 at 12:38:38PM -0500, Jon Simpson wrote:
> Hi Christopher,
>
> The patch does seem to fix the bug in my testing - I can't reproduce the
> 503 errors with your patch on 1.8. Sorry for taking a few days to get
> around to looking at this & thanks for the fix!

Much appreciated, thanks for the feedback. I'll queue it tomorrow.
Don't worry about the delay, a late confirmation is always better
than none.

Thanks!
Willy
Sorry, only registered users may post in this forum.

Click here to login