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

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

     [ https://issues.apache.org/jira/browse/CALCITE-4196?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Josh Elser resolved CALCITE-4196.
---------------------------------
    Resolution: Fixed

Fixed in f9837420cfabf88874eeb2c0a5b9642ebe2c2461. Thanks to Kevin (and Vladimir) for the reviews.

> 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
>            Priority: Critical
>             Fix For: avatica-1.18.0
>
>          Time Spent: 1h 10m
>  Remaining Estimate: 0h
>
> 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)