On Wed, 2011-09-07 at 05:41 -0700, Patrick Lightbody wrote: > 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.
Patrick if the auth cache is correctly configured you should be able to a message "Re-using cached 'BASIC' auth scheme for neustar.pagerduty.com:443" in the log http://hc.apache.org/httpcomponents-client-ga/httpclient/xref/org/apache/http/client/protocol/RequestAuthCache.html#112 Oleg > > 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 <patr...@lightbody.net> > > 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: dev-unsubscr...@hc.apache.org > >>> For additional commands, e-mail: dev-h...@hc.apache.org > >>> > >> > >> > > > > --------------------------------------------------------------------- > > To unsubscribe, e-mail: dev-unsubscr...@hc.apache.org > > For additional commands, e-mail: dev-h...@hc.apache.org > > > --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@hc.apache.org For additional commands, e-mail: dev-h...@hc.apache.org
