On Fri, 2018-07-27 at 21:14 +0000, [email protected] wrote:
> Thank you for your patience with me __
>
> In the case where close is called and there is data still to be read,
> would it be possible to read to the end?
Of course it would and I do not understand why Jersey does not bother
to do so.
try (CloseableHttpResponse response1 = client.execute(httpGet)) {
HttpEntity entity = response1.getEntity();
// 1. Always close content stream with try-with-resources
if (entity != null) {
try (InputStream inputStream = entity.getContent()) {
}
}
// 2. Or use EntityUtils#consume to consume the rest of the
// enitity content
EntityUtils.consume(entity);
}
Oleg
> Wouldn't that take care of the garbage problem?
> That would make the library more resilient to client vagaries.
>
> On 7/25/18, 1:31 AM, "Oleg Kalnichevski" <[email protected]> wrote:
>
> On Wed, 2018-07-25 at 01:11 +0000, [email protected] wrote:
> > How would you suggest we address this bug?
>
> By kindly asking Jersey developers to fix it.
>
>
> > Right now it looks like if you use jersey (and possibly other
> > libraries as well) with httpcomponent it does not work properly
> with
> > both gzip and chunked encoding.
> > Can you help me understand why the client can not assume the
> > connection is safe for re-use if it does not read until the
> end? Why
> > is that a requirement?
> >
>
> If the closing chunk does not get consumed and the connection get
> re-
> used for another message exchange, on the next exchange the
> client gets
> garbage from the previous exchange instead of a valid response
> message.
>
> Oleg
>
>
> > Thanks for your help on this.
> >
> >
> > Can you help me understand why it is some imp
> >
> > On 7/24/18, 12:19 AM, "Oleg Kalnichevski" <[email protected]>
> wrote:
> >
> > On Mon, 2018-07-23 at 17:21 +0000, [email protected]
> wrote:
> > > Oleg,
> > >
> > > The data is properly formatted, and there is a closing
> chunk.
> > On
> > > further investigation it turns out that the problem is a
> > combination
> > > of both gzip and chunk encoding turned on.
> > > The gzip decoder knows exactly how many bytes it needs
> and
> > pulls
> > > exactly that number (at least our jersey version of it
> seems
> > to) --
> > > so we never get to the closing block. Jersey then sends a
> close
> > to
> > > the file which causes it to close for real. Which is very
> much
> > not
> > > what we want.
> > >
> > > The question is whether it is legitimate for a client to
> send
> > close
> > > to a http connection using chunks without having read all
> the
> > way to
> > > the end. I would argue that it is.
> > >
> >
> > It is legitimate but if the consumer stops reading from the
> > content
> > stream without reading until the end of the stream the
> client
> > cannot
> > assume the connection to be safe for re-use.
> >
> > Oleg
> >
> > >
> > > On 7/20/18, 1:02 AM, "Oleg Kalnichevski" <[email protected]
> g>
> > wrote:
> > >
> > > On Thu, 2018-07-19 at 01:07 +0000, Odysseus.Levy@sony
> .com
> > wrote:
> > > > I am seeing a problem where
> ConnectionHolder.close() is
> > getting
> > > > called before ConnectionHolder.release() is called.
> This
> > > results in
> > > > immediately closing the connection even though we
> want to
> > keep
> > > it
> > > > around.
> > > >
> > > > This happens only with chunked responses. What
> appears to
> > > happen is
> > > > that jersey reads the last chunk with data and then
> > closes the
> > > > connection – which ultimately gets sent to
> > > ConnectionHolder.close().
> > > > Since eof has not yet been found (we don’t seem
> to get
> > to the
> > > > nextChunk() call that reads the 0 chunk), it means
> the
> > > underlying
> > > > connection gets closed.
> > > >
> > >
> > > This issue has been reported and looked into on more
> than
> > one
> > > occasion.
> > > HttpClient behavior is correct. It is not safe to re-
> use a
> > > connection
> > > with a chunk coded response message whose data stream
> has
> > not
> > > been
> > > terminated by a closing chunk.
> > >
> > > Oleg
> > >
> > >
> > > > If I change this code
> > > >
> > > > @Override
> > > > public void close() throws IOException {
> > > > releaseConnection(false);
> > > > }
> > > >
> > > > To simply this:
> > > >
> > > > @Override
> > > > public void close() throws IOException {
> > > > releaseConnection(reusable);
> > > > }
> > > >
> > > > I no longer have the connection getting immediately
> > dropped.
> > > (This
> > > > does break a unit test, though).
> > > >
> > > > Here is some sample log output at debug level with
> the
> > problem:
> > > >
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,282 +0000 DEBUG
> 117161
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > HTTP/1.1
> > > > 200 OK
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > Server:
> > > > nginx/1.13.10
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > Date:
> > > > Tue, 17 Jul 2018 21:12:46 GMT
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > Content-
> > > > Type: application/json;charset=UTF-8
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > > Transfer-Encoding: chunked
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > > Connection: keep-alive
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > << X-
> > > > RequestId: 16073adf3336513470aff4bcc23005d6
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > << X-
> > > > CorrelationId: f1f6c4cb-9f09-42a6-b5ce-8544592bd50b
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > << X-
> > > > Content-Type-Options: nosniff
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > << x-
> > > wily-
> > > > info: Clear guid=AA169DAC0ADB81C5151380A28398C79E
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > << x-
> > > wily-
> > > > servlet: Encrypt1
> > > >
> > >
> >
> hR/KG2GOR16aRfvv3/q1AY6IOmaQiRHSVfF4o38i8Nb6NeyR36CyvkJdrtOXs+Q6i7zEX
> > > >
> > >
> >
> S+Izr9EdU/xAf5ZhxHw0ow/QkacutvAiuKKILiB5+OqdEgjMxWr7r3IdRDJNdPklBSMvG
> > > >
> lPzS6DStuVPPHYlVqYfLeF5wTGvWuAivcjp7Io/wzYPActeNQCNkRr
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > Cache-
> > > > Control: private, must-revalidate, max-age=3600
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > Expires:
> > > > Wed, 18 Jul 2018 09:12:45 GMT
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,283 +0000 DEBUG
> 117162
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] headers [] - http-
> outgoing-5
> > <<
> > > Content-
> > > > Encoding: gzip
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,284 +0000 DEBUG
> 117163
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] MainClientExec [] -
> > Connection can
> > > be
> > > > kept alive indefinitely
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,284 +0000 DEBUG
> 117163
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] wire [] - http-
> outgoing-5 <<
> > > "a[\r][\n]"
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,284 +0000 DEBUG
> 117163
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] wire [] - http-
> outgoing-5 <<
> > > >
> "[0x3][0x0][0xc1]/[0xd7][0x14]U[\r][0x0][0x0][\r][\n]"
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,284 +0000 DEBUG
> 117163
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] wire [] - http-
> outgoing-5 <<
> > > "0[\r][\n]"
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,284 +0000 DEBUG
> 117163
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] wire [] - http-
> outgoing-5 <<
> > > "[\r][\n]"
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,285 +0000 DEBUG
> 117164
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff]
> > DefaultManagedHttpClientConnection
> > > [] -
> > > > http-outgoing-5: Close connection
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,285 +0000 DEBUG
> 117164
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] MainClientExec [] -
> > Connection
> > > discarded
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,285 +0000 DEBUG
> 117164
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff]
> > PoolingHttpClientConnectionManager
> > > [] -
> > > > Connection released: [id: 5][route: {s}->https://ka
> maji.a
> > uth.ap
> > > i.np.a
> > > > c.playstation.net:443][total kept alive: 0; route
> > allocated: 3
> > > of
> > > > 500; total allocated: 3 of 1000]
> > > >
> > > > tokenstatus 2018-07-17 21:12:46,285 +0000 DEBUG
> 117164
> > > [511e5d7a-
> > > > 4e5d-496d-ac27-37778b0e1eff] wire [] - http-
> outgoing-5 <<
> > > "[read] I/O
> > > > error: Socket is closed"
> > > >
> > > > And here is log output with the problem solved:
> > > >
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > HTTP/1.1 200
> > > > OK
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > Server:
> > > > nginx/1.13.10
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > Date:
> > > Thu,
> > > > 19 Jul 2018 00:32:19 GMT
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > Content-
> > > > Type: application/json;charset=UTF-8
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > Transfer-
> > > > Encoding: chunked
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > Connection:
> > > > keep-alive
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > X-
> > > RequestId:
> > > > 49e6b565d40253cfc320547931f80a50
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > X-
> > > > CorrelationId: 9031d94b-133e-495b-aa99-39a5ffff7c65
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > X-
> > > Content-
> > > > Type-Options: nosniff
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > x-
> > > wily-info:
> > > > Clear guid=AFF3AC6D0ADB813826D1845C71D1DA71
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > x-
> > > wily-
> > > > servlet: Encrypt1
> > > >
> > >
> >
> hR/KG2GOR16aRfvv3/q1AcDfNQfBP1AWkr5Dck/nEoqU5/Ft5cGKgUaFVMBigeSiwiPcI
> > > >
> > >
> >
> oX+2ikKbgkrgUodlPY7ogzMDnags9JMk3ktv98z33D2MCUqLopn132Nh2CW5UibmV9ShP
> > > >
> jWXFiphiHtL5GZ7ugYXVvCWt5z0kf7Dg55aD9Tou8pNiwZ0gzxvG5+
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > Cache-
> > > > Control: private, must-revalidate, max-age=3600
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > Expires:
> > > > Thu, 19 Jul 2018 12:31:30 GMT
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] headers [] - http-outgoing-
> 13 <<
> > > Content-
> > > > Encoding: gzip
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] MainClientExec [] -
> Connection
> > can be
> > > kept
> > > > alive indefinitely
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > > length: 31
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > > length: 139
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > > length: 8
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > > length: 0
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > off: 0
> > > len:
> > > > 6 return: 6
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > off: 0
> > > len:
> > > > 512 return: 512
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > off: 0
> > > len:
> > > > 512 return: 512
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > off: 0
> > > len:
> > > > 512 return: 62
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] wire [] - http-outgoing-13
> <<
> > > "a[\r][\n]"
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] wire [] - http-outgoing-13
> <<
> > > >
> > "[0x3][0x0][0x8][0x8a][0xc3][0xb8]6[\r][0x0][0x0][\r][\n]"
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] wire [] - http-outgoing-13
> <<
> > > "0[\r][\n]"
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] wire [] - http-outgoing-13
> <<
> > > "[\r][\n]"
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] EofSensorInputStream [] -
> read()
> > off: 0
> > > len:
> > > > 512 return: 10
> > > > tokenstatus 2018-07-19 00:32:19,585 +0000 DEBUG
> 49853
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce] MainClientExec [] -
> Connection
> > Holder;
> > > > releaseConnection; reusable: true
> > > > tokenstatus 2018-07-19 00:32:19,586 +0000 DEBUG
> 49854
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce]
> > PoolingHttpClientConnectionManager [] -
> > > > Connection [id: 13][route: {s}->https://kamaji.auth
> .api.n
> > p.ac.p
> > > laysta
> > > > tion.net:443] can be kept alive indefinitely
> > > > tokenstatus 2018-07-19 00:32:19,586 +0000 DEBUG
> 49854
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce]
> > DefaultManagedHttpClientConnection [] -
> > > http-
> > > > outgoing-13: set socket timeout to 0
> > > > tokenstatus 2018-07-19 00:32:19,586 +0000 DEBUG
> 49854
> > > [a1039839-20bb-
> > > > 4d1b-adaf-4950aef0e1ce]
> > PoolingHttpClientConnectionManager [] -
> > > > Connection released: [id: 13][route: {s}->https://k
> amaji.
> > auth.a
> > > pi.np.
> > > > ac.playstation.net:443][total kept alive: 11; route
> > allocated:
> > > 11 of
> > > > 500; total allocated: 11 of 1000]
> > > >
> > > > Note that I added some extra debug statements to
> get a
> > better
> > > idea of
> > > > the problem. In particular I added debug statements
> to
> > > > EofSensorInputStream.read()
> > > >
> > >
> > > -----------------------------------------------------
> ------
> > ------
> > > ----
> > > To unsubscribe, e-mail: [email protected]
> > > For additional commands, e-mail: [email protected]
> rg
> > >
> > >
> > >
> > >
> > > -------------------------------------------------------
> ------
> > --------
> > > To unsubscribe, e-mail: [email protected]
> > > For additional commands, e-mail: [email protected]
> > >
> >
> > -----------------------------------------------------------
> ------
> > ----
> > To unsubscribe, e-mail: [email protected]
> > For additional commands, e-mail: [email protected]
> >
> >
> >
> >
> > -------------------------------------------------------------
> --------
> > To unsubscribe, e-mail: [email protected]
> > For additional commands, e-mail: [email protected]
> >
>
> -----------------------------------------------------------------
> ----
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [email protected]
> For additional commands, e-mail: [email protected]
>
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
