You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@calcite.apache.org by "Josh Elser (Jira)" <ji...@apache.org> on 2020/08/26 17:38:00 UTC

[jira] [Created] (CALCITE-4196) Avatica server responds with HTTP/401 prior to consuming all data written by client

Josh Elser created CALCITE-4196:
-----------------------------------

             Summary: Avatica server responds with HTTP/401 prior to consuming all data written by client
                 Key: CALCITE-4196
                 URL: https://issues.apache.org/jira/browse/CALCITE-4196
             Project: Calcite
          Issue Type: Bug
          Components: avatica
            Reporter: Josh Elser
            Assignee: Josh Elser
             Fix For: avatica-1.18.0


First off, big thanks to [~krisden] for pointing me to HIVE-22231 which was the similar problem on the Hive side.

Symptoms: the client, when sending a large HTTP request to the Avatica server which is configured for SPNEGO authentication, e.g. an ExecuteBatchRequest with 100's to 1000's of rows to execute, will receive an HTTP/401 response as a part of the normal SPNEGO negotiation (described in [https://tools.ietf.org/html/rfc4559#section-5]). The client will observe an error similar to the following, indicate "Broken pipe".
{noformat}
2020-08-24 17:21:54,512 DEBUG http.wire: http-outgoing-1 >> "[write] I/O error: Broken pipe (Write failed)"
2020-08-24 17:21:54,512 DEBUG conn.DefaultManagedHttpClientConnection: http-outgoing-1: Close connection
2020-08-24 17:21:54,512 DEBUG conn.DefaultManagedHttpClientConnection: http-outgoing-1: Shutdown connection
2020-08-24 17:21:54,512 DEBUG execchain.MainClientExec: Connection discarded
2020-08-24 17:21:54,512 DEBUG conn.PoolingHttpClientConnectionManager: Connection released: [id: 1][route: {}->http://avatica-server:8765][total kept alive: 0; route allocated: 0 of 25; total allocated: 0 of 100]
2020-08-24 17:21:54,512 INFO execchain.RetryExec: I/O exception (java.net.SocketException) caught when processing request to {}->http://avatica-server:8765: Broken pipe (Write failed)
2020-08-24 17:21:54,512 DEBUG execchain.RetryExec: Broken pipe (Write failed)
java.net.SocketException: Broken pipe (Write failed)
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
        at org.apache.calcite.avatica.org.apache.http.impl.conn.LoggingOutputStream.write(LoggingOutputStream.java:74)
        at org.apache.calcite.avatica.org.apache.http.impl.io.SessionOutputBufferImpl.streamWrite(SessionOutputBufferImpl.java:124)
        at org.apache.calcite.avatica.org.apache.http.impl.io.SessionOutputBufferImpl.write(SessionOutputBufferImpl.java:160)
        at org.apache.calcite.avatica.org.apache.http.impl.io.ContentLengthOutputStream.write(ContentLengthOutputStream.java:113)
        at org.apache.calcite.avatica.org.apache.http.entity.ByteArrayEntity.writeTo(ByteArrayEntity.java:112)
        at org.apache.calcite.avatica.org.apache.http.impl.DefaultBHttpClientConnection.sendRequestEntity(DefaultBHttpClientConnection.java:156)
        at org.apache.calcite.avatica.org.apache.http.impl.conn.CPoolProxy.sendRequestEntity(CPoolProxy.java:152)
        at org.apache.calcite.avatica.org.apache.http.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:238)
        at org.apache.calcite.avatica.org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
        at org.apache.calcite.avatica.org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
        at org.apache.calcite.avatica.org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
        at org.apache.calcite.avatica.org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
        at org.apache.calcite.avatica.org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
        at org.apache.calcite.avatica.org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
        at org.apache.calcite.avatica.org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
        at org.apache.calcite.avatica.remote.AvaticaCommonsHttpClientSpnegoImpl.send(AvaticaCommonsHttpClientSpnegoImpl.java:129)
        at org.apache.calcite.avatica.remote.DoAsAvaticaHttpClient$1.run(DoAsAvaticaHttpClient.java:39)
        at org.apache.calcite.avatica.remote.DoAsAvaticaHttpClient$1.run(DoAsAvaticaHttpClient.java:37)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:360)
        at org.apache.calcite.avatica.remote.DoAsAvaticaHttpClient.send(DoAsAvaticaHttpClient.java:37)
        at org.apache.calcite.avatica.remote.RemoteProtobufService._apply(RemoteProtobufService.java:44)
        at org.apache.calcite.avatica.remote.ProtobufService.apply(ProtobufService.java:117)
        at org.apache.calcite.avatica.remote.RemoteMeta$20.call(RemoteMeta.java:430)
        at org.apache.calcite.avatica.remote.RemoteMeta$20.call(RemoteMeta.java:427)
        at org.apache.calcite.avatica.AvaticaConnection.invokeWithRetries(AvaticaConnection.java:793)
        at org.apache.calcite.avatica.remote.RemoteMeta.executeBatch(RemoteMeta.java:427)
        at org.apache.calcite.avatica.AvaticaConnection.executeBatchUpdateInternal(AvaticaConnection.java:593)
        at org.apache.calcite.avatica.AvaticaPreparedStatement.executeLargeBatch(AvaticaPreparedStatement.java:266)
        at org.apache.calcite.avatica.AvaticaPreparedStatement.executeBatch(AvaticaPreparedStatement.java:259)
        at TestThinClient.main(TestThinClient.java:62) {noformat}
What happens: as a result of how Jetty operates, the request will be dispatched into the Avatica Handler classes before all of the data has been read off of the wire. Jetty will notice that the request does not come with the WWW-Authenticate challenge response, so it will immediately trigger the code to respond to the client and begin the handshake process.

Why Avatica/Jetty do this, the client is still in the process of sending the data over the wire, but Avatica/Jetty is "done" processing this request and closes the socket. As the client continues to write the rest of the data (for the request which Avatica has already responded to with HTTP/401), Jetty will send back a TCP reset and close the socket.

The result is that the client sees an exception like above. Again, note, this will only happen with SPNEGO being enabled. It would not happen for no authentication or Basic/Digest authentication.

All this considered, the solution is simple: read all of the data the client is sending prior to replying back with the HTTP/401.



--
This message was sent by Atlassian Jira
(v8.3.4#803005)