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)
