Uploaded image for project: 'Hive'
  1. Hive
  2. HIVE-25627

Subsequent post to hive endpoint results in 401, then reauth with credentials

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Open
    • Major
    • Resolution: Unresolved
    • 3.1.1, 4.0.0
    • None
    • JDBC
    • None

    Description

      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 

      1. Authenticate with creds (status 200).
      2. HTTP request gets "HTTP/1.1 401 - Authentication failed" Credentials were missing
      3. Auth cache not set in the context
      4. Retry with creds (succeeds)

       

      Reprod:

      1. Enable the beeline jdbc DEBUG logs
      2. Use beeline to enter your cluster through a public endpoint using username/password

       

      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
      21/10/19 23:05:38 [main]: DEBUG protocol.RequestAddCookies: CookieSpec selected: default
      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]
      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]
      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]
      21/10/19 23:05:38 [main]: DEBUG protocol.RequestAuthCache: Auth cache not set in the context
      21/10/19 23:05:38 [main]: DEBUG conn.BasicHttpClientConnectionManager: Get connection for route {s}->https://cluster40.azurehdinsight.net:443
      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

       

       

       

      Attachments

        Activity

          People

            Unassigned Unassigned
            kecheung Kevin Cheung
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated: