[
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)
