OK, is this what you're looking for? I'm not seeing anything about a cached
AuthScheme, but as you can see once it sees the 401 challenge it responds just
fine with the proper Basic auth header.
FINE 09/07 12:36:49 o.a.h.i.c.t.ThreadS~ - Get connection:
HttpRoute[{s}->https://neustar.pagerduty.com], timeout = 0
FINE 09/07 12:36:49 o.a.h.i.c.t.ConnPoo~ -
[HttpRoute[{s}->https://neustar.pagerduty.com]] total kept alive: 0, total
issued: 0, total allocated: 0 out of 4
FINE 09/07 12:36:49 o.a.h.i.c.t.ConnPoo~ - No free connections
[HttpRoute[{s}->https://neustar.pagerduty.com]][null]
FINE 09/07 12:36:49 o.a.h.i.c.t.ConnPoo~ - Available capacity: 4 out of 4
[HttpRoute[{s}->https://neustar.pagerduty.com]][null]
FINE 09/07 12:36:49 o.a.h.i.c.t.ConnPoo~ - Creating new connection
[HttpRoute[{s}->https://neustar.pagerduty.com]]
FINE 09/07 12:36:49 o.a.h.i.c.DefaultCl~ - Connecting to
neustar.pagerduty.com:443
FINE 09/07 12:36:50 o.a.h.c.p.RequestAd~ - CookieSpec selected: best-match
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Attempt 1 to execute request
FINE 09/07 12:36:50 o.a.h.i.c.DefaultCl~ - Sending request: GET
/api/v1/incidents/count HTTP/1.1
FINE 09/07 12:36:50 org.apache.http.wire - >> "GET /api/v1/incidents/count
HTTP/1.1[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Host:
neustar.pagerduty.com[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Connection: Keep-Alive[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "User-Agent: PagerDuty
Client/UNKNOWN/DEVELOPMENT[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "[\r][\n]"
FINE 09/07 12:36:50 o.a.h.headers - >> GET /api/v1/incidents/count
HTTP/1.1
FINE 09/07 12:36:50 o.a.h.headers - >> Host: neustar.pagerduty.com
FINE 09/07 12:36:50 o.a.h.headers - >> Connection: Keep-Alive
FINE 09/07 12:36:50 o.a.h.headers - >> User-Agent: PagerDuty
Client/UNKNOWN/DEVELOPMENT
FINE 09/07 12:36:50 org.apache.http.wire - << "HTTP/1.1 401
Unauthorized[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Server: nginx/0.8.53[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Date: Wed, 07 Sep 2011 12:36:51
GMT[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Content-Type: text/html;
charset=utf-8[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Connection: keep-alive[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Status: 401[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "X-Powered-By: Phusion Passenger
(mod_rails/mod_rack) 3.0.2[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "WWW-Authenticate: Basic
realm="Web Password"[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "X-Runtime: 8[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Content-Length: 27[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Set-Cookie:
_pagerduty_session=BAh7BjoPc2Vzc2lvbl9pZCIlYWEyZWU3NTJiZTA1MjE2OTI2OTBlMGRhNDg1NzkwYTk%3D--4fc3da81878bfc319d363fd62f6c8ccf531c9fc4;
path=/; HttpOnly[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Cache-Control: no-cache[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "Set-Cookie:
uid=CsqVu05nZWMa8D96BdE2Ag==; expires=Thu, 31-Dec-37 23:55:55 GMT;
domain=pagerduty.com; path=/[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - << "[\r][\n]"
FINE 09/07 12:36:50 o.a.h.i.c.DefaultCl~ - Receiving response: HTTP/1.1 401
Unauthorized
FINE 09/07 12:36:50 o.a.h.headers - << HTTP/1.1 401 Unauthorized
FINE 09/07 12:36:50 o.a.h.headers - << Server: nginx/0.8.53
FINE 09/07 12:36:50 o.a.h.headers - << Date: Wed, 07 Sep 2011 12:36:51
GMT
FINE 09/07 12:36:50 o.a.h.headers - << Content-Type: text/html;
charset=utf-8
FINE 09/07 12:36:50 o.a.h.headers - << Connection: keep-alive
FINE 09/07 12:36:50 o.a.h.headers - << Status: 401
FINE 09/07 12:36:50 o.a.h.headers - << X-Powered-By: Phusion Passenger
(mod_rails/mod_rack) 3.0.2
FINE 09/07 12:36:50 o.a.h.headers - << WWW-Authenticate: Basic
realm="Web Password"
FINE 09/07 12:36:50 o.a.h.headers - << X-Runtime: 8
FINE 09/07 12:36:50 o.a.h.headers - << Content-Length: 27
FINE 09/07 12:36:50 o.a.h.headers - << Set-Cookie:
_pagerduty_session=************************; path=/; HttpOnly
FINE 09/07 12:36:50 o.a.h.headers - << Cache-Control: no-cache
FINE 09/07 12:36:50 o.a.h.headers - << Set-Cookie:
uid=CsqVu05nZWMa8D96BdE2Ag==; expires=Thu, 31-Dec-37 23:55:55 GMT;
domain=pagerduty.com; path=/
FINE 09/07 12:36:50 o.a.h.c.p.ResponseP~ - Cookie accepted: "[version: 0][name:
_pagerduty_session][value: **************************][domain:
neustar.pagerduty.com][path: /][expiry: null]".
FINE 09/07 12:36:50 o.a.h.c.p.ResponseP~ - Cookie accepted: "[version: 0][name:
uid][value: CsqVu05nZWMa8D96BdE2Ag==][domain: pagerduty.com][path: /][expiry:
Thu Dec 31 15:55:55 PST 2037]".
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Connection can be kept alive
indefinitely
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Target requested authentication
FINE 09/07 12:36:50 o.a.h.i.c.DefaultTa~ - Authentication schemes in the order
of preference: [negotiate, NTLM, Digest, Basic]
FINE 09/07 12:36:50 o.a.h.i.c.DefaultTa~ - Challenge for negotiate
authentication scheme not available
FINE 09/07 12:36:50 o.a.h.i.c.DefaultTa~ - Challenge for NTLM authentication
scheme not available
FINE 09/07 12:36:50 o.a.h.i.c.DefaultTa~ - Challenge for Digest authentication
scheme not available
FINE 09/07 12:36:50 o.a.h.i.c.DefaultTa~ - Basic authentication scheme selected
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Authorization challenge processed
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Authentication scope: BASIC 'Web
Password'@neustar.pagerduty.com:443
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Found credentials
FINE 09/07 12:36:50 org.apache.http.wire - << "HTTP Basic: Access denied.[\n]"
FINE 09/07 12:36:50 o.a.h.c.p.RequestAd~ - CookieSpec selected: best-match
FINE 09/07 12:36:50 o.a.h.c.p.RequestAd~ - Cookie [version: 0][name:
_pagerduty_session][value: ***********************][domain:
neustar.pagerduty.com][path: /][expiry: null] match
[(secure)neustar.pagerduty.com:443/api/v1/incidents/count]
FINE 09/07 12:36:50 o.a.h.c.p.RequestAd~ - Cookie [version: 0][name:
uid][value: CsqVu05nZWMa8D96BdE2Ag==][domain: pagerduty.com][path: /][expiry:
Thu Dec 31 15:55:55 PST 2037] match
[(secure)neustar.pagerduty.com:443/api/v1/incidents/count]
FINE 09/07 12:36:50 b.n.p.PagerDutyHttp~ - Attempt 2 to execute request
FINE 09/07 12:36:50 o.a.h.i.c.DefaultCl~ - Sending request: GET
/api/v1/incidents/count HTTP/1.1
FINE 09/07 12:36:50 org.apache.http.wire - >> "GET /api/v1/incidents/count
HTTP/1.1[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Host:
neustar.pagerduty.com[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Connection: Keep-Alive[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "User-Agent: PagerDuty
Client/UNKNOWN/DEVELOPMENT[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Cookie:
_pagerduty_session=*************************;
uid=CsqVu05nZWMa8D96BdE2Ag==[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Cookie2: $Version=1[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "Authorization: Basic
************************************************=[\r][\n]"
FINE 09/07 12:36:50 org.apache.http.wire - >> "[\r][\n]"
FINE 09/07 12:36:50 o.a.h.headers - >> GET /api/v1/incidents/count
HTTP/1.1
FINE 09/07 12:36:50 o.a.h.headers - >> Host: neustar.pagerduty.com
FINE 09/07 12:36:50 o.a.h.headers - >> Connection: Keep-Alive
FINE 09/07 12:36:50 o.a.h.headers - >> User-Agent: PagerDuty
Client/UNKNOWN/DEVELOPMENT
FINE 09/07 12:36:50 o.a.h.headers - >> Cookie:
_pagerduty_session=***************************; uid=CsqVu05nZWMa8D96BdE2Ag==
FINE 09/07 12:36:50 o.a.h.headers - >> Cookie2: $Version=1
FINE 09/07 12:36:50 o.a.h.headers - >> Authorization: Basic
***************************************************=
FINE 09/07 12:36:51 org.apache.http.wire - << "HTTP/1.1 200 OK[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Server: nginx/0.8.53[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Date: Wed, 07 Sep 2011 12:36:51
GMT[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Content-Type: application/json;
charset=utf-8[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Connection: keep-alive[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Status: 200[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "X-Powered-By: Phusion Passenger
(mod_rails/mod_rack) 3.0.2[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "ETag:
"0d78d7323cc7826249dd9099d8085360"[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "X-Runtime: 66[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Content-Length: 13[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Set-Cookie:
_pagerduty_session=*****************************; path=/; HttpOnly[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "Cache-Control: private,
max-age=0, must-revalidate[\r][\n]"
FINE 09/07 12:36:51 org.apache.http.wire - << "[\r][\n]"
FINE 09/07 12:36:51 o.a.h.i.c.DefaultCl~ - Receiving response: HTTP/1.1 200 OK
FINE 09/07 12:36:51 o.a.h.headers - << HTTP/1.1 200 OK
FINE 09/07 12:36:51 o.a.h.headers - << Server: nginx/0.8.53
FINE 09/07 12:36:51 o.a.h.headers - << Date: Wed, 07 Sep 2011 12:36:51
GMT
FINE 09/07 12:36:51 o.a.h.headers - << Content-Type: application/json;
charset=utf-8
FINE 09/07 12:36:51 o.a.h.headers - << Connection: keep-alive
FINE 09/07 12:36:51 o.a.h.headers - << Status: 200
FINE 09/07 12:36:51 o.a.h.headers - << X-Powered-By: Phusion Passenger
(mod_rails/mod_rack) 3.0.2
FINE 09/07 12:36:51 o.a.h.headers - << ETag:
"0d78d7323cc7826249dd9099d8085360"
FINE 09/07 12:36:51 o.a.h.headers - << X-Runtime: 66
FINE 09/07 12:36:51 o.a.h.headers - << Content-Length: 13
FINE 09/07 12:36:51 o.a.h.headers - << Set-Cookie:
_pagerduty_session=*************************; path=/; HttpOnly
FINE 09/07 12:36:51 o.a.h.headers - << Cache-Control: private,
max-age=0, must-revalidate
FINE 09/07 12:36:51 o.a.h.c.p.ResponseP~ - Cookie accepted: "[version: 0][name:
_pagerduty_session][value: *****************************][domain:
neustar.pagerduty.com][path: /][expiry: null]".
FINE 09/07 12:36:51 o.a.h.c.p.ResponseA~ - Caching 'basic' auth scheme for
https://neustar.pagerduty.com
FINE 09/07 12:36:51 b.n.p.PagerDutyHttp~ - Connection can be kept alive
indefinitely
FINE 09/07 12:36:51 org.apache.http.wire - << "{"total":764}"
FINE 09/07 12:36:51 o.a.h.i.c.t.ThreadS~ - Released connection is reusable.
FINE 09/07 12:36:51 o.a.h.i.c.t.ConnPoo~ - Releasing connection
[HttpRoute[{s}->https://neustar.pagerduty.com]][null]
FINE 09/07 12:36:51 o.a.h.i.c.t.ConnPoo~ - Pooling connection
[HttpRoute[{s}->https://neustar.pagerduty.com]][null]; keep alive indefinitely
FINE 09/07 12:36:51 o.a.h.i.c.t.ConnPoo~ - Notifying no-one, there are no
waiting threads
On Sep 6, 2011, at 7:14 PM, Bill Speirs wrote:
> Just enabled Debug logging via commons-logging. A simple log4j
> properties file should do the trick.
>
> Bill-
>
> On Tue, Sep 6, 2011 at 6:06 PM, Patrick Lightbody <[email protected]>
> wrote:
>> Oleg,
>> Thanks for the quick reply. One question: Is that an API call, or simply
>> turning on low-level log statements for the BasicHttpContext class via
>> commons-logging?
>>
>> Patrick
>>
>> On Sep 6, 2011, at 2:36 PM, Oleg Kalnichevski wrote:
>>
>>> On Tue, 2011-09-06 at 14:29 -0700, Patrick Lightbody wrote:
>>>> I read the docs + examples for preemptive basic auth, but it still doesn't
>>>> look to be working. I started debugging the code and I'm actually not sure
>>>> how it could work. Please let me know if I'm misunderstanding how the
>>>> internals of HttpClient works, but here's what I observed:
>>>>
>>>> * RequestTargetAuthentication is responsible for adding the auth headers
>>>> * RequestTargetAuthentication looks for an AuthState object that has
>>>> non-null scheme & creds objects that are used for the header
>>>> * DefaultRequestDirector creates an empty AuthState object on each new
>>>> request (targetAuthState field)
>>>> * DefaultRequestDirector only updates the targetAuthState fields after it
>>>> makes an initial request that returns a 401
>>>>
>>>> So what I'm finding in my debugging is that even though I've set up my
>>>> CredentialsProvider with the correct authScope +
>>>> UsernamePasswordCredentials and that I've set my HttpContext (global or
>>>> local, doesn't matter) with the proper AuthCache + BasicScheme, I still
>>>> end up with two queries: 401 and then finally a 200. In other words, it
>>>> doesn't seem to be preemptive.
>>>>
>>>> Any idea what I might be doing wrong? Or maybe I'm just misunderstanding
>>>> how DefaultRequestDirector does it's loop inside execute()?
>>>>
>>>> Patrick
>>>>
>>>
>>>
>>> If you turn of context logging you should be able to see whether or not
>>> the cached auth scheme is being re-used.
>>>
>>> Oleg
>>>
>>>
>>> ---------------------------------------------------------------------
>>> To unsubscribe, e-mail: [email protected]
>>> For additional commands, e-mail: [email protected]
>>>
>>
>>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>
