[
https://issues.apache.org/jira/browse/HIVE-25627?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Kevin Cheung updated HIVE-25627:
--------------------------------
Summary: Subsequent post to hive endpoint results in 401, then reauth with
credentials (was: Subsequent post success to hive endpoint results in 401,
then reauth with credentials)
> Subsequent post to hive endpoint results in 401, then reauth with credentials
> -----------------------------------------------------------------------------
>
> Key: HIVE-25627
> URL: https://issues.apache.org/jira/browse/HIVE-25627
> Project: Hive
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 3.1.1, 4.0.0
> Reporter: Kevin Cheung
> Priority: Major
>
> Opening beeline with DEBUG logs enables shows a pattern of doing. It looks
> like there is no httpclientcontext, the authCache is null and therefore
> cannot use cached credential information so it must reauthenticate with the
> actual username/pass.
>
> [https://github.com/apache/httpcomponents-client/blob/a0b85d44c26430ff8354a0af5a1b7d58e2e5bce5/httpclient/src/main/java/org/apache/http/client/protocol/RequestAuthCache.java#L77]
>
> # Authenticate with creds (status 200).
> # HTTP request gets "HTTP/1.1 401 - Authentication failed" Credentials were
> missing
> # Auth cache not set in the context
> # Retry with creds (succeeds)
>
> Showing beeline console output with debug logs: Logs start with status 200
> authenticating with username/pass, but then subsequent request leads to 401
> and requires reauth again.
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << HTTP/1.1 200
> OK
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Content-Type: application/x-thrift
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Content-Encoding: gzip
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Vary:
> Accept-Encoding, User-Agent
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << request-id:
> e9339125c2f84d0b857d36129b4851f2
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-active:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-http-host:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-http-gateway: gw0-cluster
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-host: hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Strict-Transport-Security: max-age=31536000; includeSubDomains
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Set-Cookie:
> JSESSIONID=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net;
> expires=Wed, 20-Oct-2021 23:05:38 GMT; path=/; secure
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Set-Cookie:
> x-ms-hdi-host=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net;
> path=/; secure
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Set-Cookie:
> hive.server2.auth=cu=admin&rn=4735931476793922767&s=QNX50wcftWqEXyGNHVi9cjwP/A9awQsBtXF9fc5gamQ=;Version=0;Max-Age=86400;
> HttpOnly; path=/; secure; HttpOnly; SameSite=None
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Date: Tue,
> 19 Oct 2021 23:05:38 GMT
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Content-Length: 171
> 21/10/19 23:05:38 [main]: DEBUG execchain.MainClientExec: Connection can be
> kept alive indefinitely
> 21/10/19 23:05:38 [main]: DEBUG protocol.ResponseProcessCookies: Cookie
> accepted
> [JSESSIONID="hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net",
> version:0, domain:cluster40.azurehdinsight.net, path:/, expiry:Wed Oct 20
> 23:05:38 UTC 2021]
> 21/10/19 23:05:38 [main]: DEBUG protocol.ResponseProcessCookies: Cookie
> accepted
> [x-ms-hdi-host="hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net",
> version:0, domain:cluster40.azurehdinsight.net, path:/, expiry:null]
> 21/10/19 23:05:38 [main]: DEBUG protocol.ResponseProcessCookies: Cookie
> accepted
> [hive.server2.auth="cu=admin&rn=4735931476793922767&s=QNX50wcftWqEXyGNHVi9cjwP/A9awQsBtXF9fc5gamQ=",
> version:0, domain:cluster40.azurehdinsight.net, path:/, expiry:Wed Oct 20
> 23:05:38 UTC 2021]
> 21/10/19 23:05:38 [main]: DEBUG conn.BasicHttpClientConnectionManager:
> Releasing connection 10.0.0.5:34278<->13.72.83.213:443
> 21/10/19 23:05:38 [main]: DEBUG conn.BasicHttpClientConnectionManager:
> Connection can be kept alive indefinitely
> 21/10/19 23:05:38 [main]: DEBUG execchain.MainClientExec: Cancelling request
> execution
> 21/10/19 23:05:38 [main]: ERROR jdbc.HttpRequestInterceptorBase: cookie
> enable set retry key
> 21/10/19 23:05:38 [main]: ERROR jdbc.HttpRequestInterceptorBase:
> additionalHeaders
> 21/10/19 23:05:38 [main]: ERROR jdbc.HttpRequestInterceptorBase:
> customCookies
> 21/10/19 23:05:38 [main]: ERROR jdbc.HttpRequestInterceptorBase: process end
> {color:#de350b}21/10/19 23:05:38 [main]: DEBUG protocol.RequestAddCookies:
> CookieSpec selected: default{color}
> {color:#de350b}21/10/19 23:05:38 [main]: DEBUG protocol.RequestAddCookies:
> Cookie [version: 0][name: JSESSIONID][value:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net][domain:
> cluster40.azurehdinsight.net][path: /][expiry: Wed Oct 20 23:05:38 UTC 2021]
> match [(secure)cluster40.azurehdinsight.net:443/hive2]{color}
> {color:#de350b}21/10/19 23:05:38 [main]: DEBUG protocol.RequestAddCookies:
> Cookie [version: 0][name: hive.server2.auth][value:
> cu=admin&rn=4735931476793922767&s=QNX50wcftWqEXyGNHVi9cjwP/A9awQsBtXF9fc5gamQ=][domain:
> cluster40.azurehdinsight.net][path: /][expiry: Wed Oct 20 23:05:38 UTC 2021]
> match [(secure)cluster40.azurehdinsight.net:443/hive2]{color}
> {color:#de350b}21/10/19 23:05:38 [main]: DEBUG protocol.RequestAddCookies:
> Cookie [version: 0][name: x-ms-hdi-host][value:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net][domain:
> cluster40.azurehdinsight.net][path: /][expiry: null] match
> [(secure)cluster40.azurehdinsight.net:443/hive2]{color}
> {color:#de350b}21/10/19 23:05:38 [main]: DEBUG protocol.RequestAuthCache:
> Auth cache not set in the context{color}
> 21/10/19 23:05:38 [main]: DEBUG conn.BasicHttpClientConnectionManager: Get
> connection for route
> \{s}->[https://cluster40.azurehdinsight.net:443|https://cluster40.azurehdinsight.net/]
> 21/10/19 23:05:38 [main]: DEBUG execchain.MainClientExec: Executing request
> POST /hive2 HTTP/1.1
> 21/10/19 23:05:38 [main]: DEBUG execchain.MainClientExec: Target auth state:
> UNCHALLENGED
> 21/10/19 23:05:38 [main]: DEBUG execchain.MainClientExec: Proxy auth state:
> UNCHALLENGED
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> POST /hive2
> HTTP/1.1
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >>
> Content-Type: application/x-thrift
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> Accept:
> application/x-thrift
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> User-Agent:
> Java/THttpClient/HC
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> Cookie:
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >>
> Content-Length: 85
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> Host:
> cluster40.azurehdinsight.net:443
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> Connection:
> Keep-Alive
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >> Cookie:
> JSESSIONID=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net;
> hive.server2.auth=cu=admin&rn=4735931476793922767&s=QNX50wcftWqEXyGNHVi9cjwP/A9awQsBtXF9fc5gamQ=;
> x-ms-hdi-host=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >>
> Accept-Encoding: gzip,deflate
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 >>
> X-XSRF-HEADER: true
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "POST /hive2
> HTTP/1.1[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "Content-Type:
> application/x-thrift[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "Accept:
> application/x-thrift[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "User-Agent:
> Java/THttpClient/HC[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "Cookie:
> [\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >>
> "Content-Length: 85[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "Host:
> cluster40.azurehdinsight.net:443[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "Connection:
> Keep-Alive[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "Cookie:
> JSESSIONID=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net;
> hive.server2.auth=cu=admin&rn=4735931476793922767&s=QNX50wcftWqEXyGNHVi9cjwP/A9awQsBtXF9fc5gamQ=;
>
> x-ms-hdi-host=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >>
> "Accept-Encoding: gzip,deflate[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >>
> "X-XSRF-HEADER: true[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >> "[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 >>
> "[0x80][0x1][0x0][0x1][0x0][0x0][0x0][0x7]GetInfo[0x0][0x0][0x0][0x2][0xc][0x0][0x1][0xc][0x0][0x1][0xc][0x0][0x1][0xb][0x0][0x1][0x0][0x0][0x0][0x10][0xbc]La[0x84]j[0xe0]IU[0x86][0xb1]l2[0xd8][0xb0]0Y[0xb][0x0][0x2][0x0][0x0][0x0][0x10][0x1][0xea]^(y[0xba]H[0xcc][0xa6]_[0x2][0xc7][0xf9][0xe2][0x89]z[0x0][0x0][0x8][0x0][0x2][0x0][0x0][0x0][0x11][0x0][0x0]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "HTTP/1.1 401
> - Authentication failed[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "Cache-Control: private[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "Transfer-Encoding: chunked[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "Content-Type:
> application/json; charset=utf-8[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "request-id:
> 6954f08be3f747b5aeefa41e44a0befd[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "x-ms-hdi-active:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "x-ms-hdi-http-host:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "x-ms-hdi-http-gateway: gw0-cluster[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "x-ms-hdi-host:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "WWW-Authenticate: Basic realm=HDInsight[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "x-ms-hdi-errorcode: Credentials were missing.[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "Strict-Transport-Security: max-age=31536000; includeSubDomains[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "Set-Cookie:
> x-ms-hdi-host=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net;
> path=/[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "Date: Tue, 19
> Oct 2021 23:05:38 GMT[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 << "a3[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.wire: http-outgoing-0 <<
> "\{"Code":"Unauthorized","Message":"Credentials were
> missing.","CorrelationId":"6954f08be3f747b5aeefa41e44a0befd","ResponseTimestamp":"2021-10-19T23:05:38.6922494Z"}[\r][\n]"
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << HTTP/1.1
> 401 - Authentication failed
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Cache-Control: private
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Transfer-Encoding: chunked
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Content-Type: application/json; charset=utf-8
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << request-id:
> 6954f08be3f747b5aeefa41e44a0befd
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-active:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-http-host:
> hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-http-gateway: gw0-cluster
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-host: hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> WWW-Authenticate: Basic realm=HDInsight
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> x-ms-hdi-errorcode: Credentials were missing.
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 <<
> Strict-Transport-Security: max-age=31536000; includeSubDomains
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Set-Cookie:
> x-ms-hdi-host=hn0-cluster.hcxg3d3d41fu1ezwzrnpsapynf.bx.internal.cloudapp.net;
> path=/
> 21/10/19 23:05:38 [main]: DEBUG http.headers: http-outgoing-0 << Date: Tue,
> 19 Oct 2021 23:05:38 GMT
> 21/10/19 23:05:38 [main]: DEBUG execchain.MainClientExec: Connection can be
> kept alive indefinitely
> 21/10/19 23:05:38 [main]: DEBUG auth.HttpAuthenticator: Authentication
> required
> 21/10/19 23:05:38 [main]: DEBUG auth.HttpAuthenticator:
> cluster40.azurehdinsight.net:443 requested authentication
>
>
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
