Compression buffer too small? (#420)

Activities

Daniele Ricci opened 10 years ago

Due Date
2015-01-30

Sometimes during a compressed TLS stream I got stuck receiving data from the client. The situation unlocks only when new data must be sent to the socket.

2015-01-25 17:43:21.818 [in_13-c2s]        ConnectionManager.writePacketToSocket()  FINEST: c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465, type: accept, Socket: ZLIB: TLS: c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465 Socket[addr=/127.0.0.1,port=38465,localport=5222], jid: d96b6d3ba60e3714e98a094990bb6275e83ab46b@prime.kontalk.net/RlHH5gp7suWXT2Q5ulx7, Writing packet: from=sess-man@notebook.casaricci.it, to=c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465, DATA=<iq xmlns="jabber:client" from="d96b6d3ba60e3714e98a094990bb6275e83ab46b@prime.kontalk.net" id="oM179-6" to="d96b6d3ba60e3714e98a094990bb6275e83ab46b@prime.kontalk.net/RlHH5gp7suWXT2Q5ulx7" type="result"><pubkey xmlns="urn:xmpp:pubkey:2">mQENBFRWebUBCADnGgDIajnFbvbfPlKPrBz3cUU/CoXQN+555auAxiSXxWHtUzTByPMLAzQ1EDVIVblKQwjKejbqobCi4TcM9AhX0e7hIGPsLDcnH8G+FY7sBcW8nfG3ZrtRDpnikDdrCkhJx/viKNKyxjo5gfiN8KMiyXpTvbQyLWe0EDCYfs6rf7KDiYUc+dKG0og2hqooVaqvVB/MZaxIJUpRE79SmFbErheiJm2VmyTH0I1cqcuRDW5MwHa2WmTQdiwaWWIPTDgBcIQcxmaIBv7VDdF8fWM/b5SnnnR5/p8NnIPyKJ7OYhVOnkoR3uQ8ag6DcVzYiMmqaRe8nnp3g99RoLd96zPZABEBAAG0VURldmljZS01NTU2IChOTyBDT01NRU5UKSA8ZDk2YjZkM2JhNjBlMzcxNGU5OGEwOTQ5OTBiYjYyNzVlODNhYjQ2YkBwcmltZS5rb250YWxrLm5ldD6JARwEEwECAAYFAlRWebUACgkQBzLVy/uNkoO6Mwf+O5Wwn2461oURfHyhFgNDBSNllPkjXMTI0QbSAwY3wvYmEZj3L26SfFImhwoAWKGIRHTMgosmZoAtXzcu8hkBNntF95cH5RIeEzGAacgh6wUctmbMkW+k8o5eJcVGP8UogdACENp7Ix98aMa3U7uR5s6pX995oS8K3OfM8OlQjoeugzYIYQ/+w6YYCEmA+vc6p9sO1elQslG1ofV2kmZTMcc57mHcPzk9F2S8GqRJYiPlRckElebSSF+rVn5Ka1TGt1Yjr5UBHK ... , SIZE=1988, XMLNS=jabber:client, PRIORITY=NORMAL, PERMISSION=AUTH, TYPE=result
2015-01-25 17:43:21.820 [in_13-c2s]        ZLibIO.write()                     FINER:    ZLIB - Writing data, remaining: 1.988
2015-01-25 17:43:21.820 [in_13-c2s]        ZLibWrapper.compress()             FINEST:   Increasing compress_output size to: 1.024
2015-01-25 17:43:21.820 [in_13-c2s]        TLSIO.write()                      FINER:    TLS - Writing data, remaining: 1.024, TLS: c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465 Socket[addr=/127.0.0.1,port=38465,localport=5222]
2015-01-25 17:43:21.821 [in_13-c2s]        TLSWrapper.wrap()                  FINEST:   TLS: c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465 Socket[addr=/127.0.0.1,port=38465,localport=5222], tlsEngineRsult.getStatus() = OK, tlsEngineRsult.getHandshakeStatus() = NOT_HANDSHAKING
2015-01-25 17:43:21.821 [in_13-c2s]        SocketIO.write()                   FINER:    SOCKET - Writing data, remaining: 1.098, c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465 Socket[addr=/127.0.0.1,port=38465,localport=5222]
2015-01-25 17:43:21.821 [in_13-c2s]        SocketIO.write()                   FINER:    Wrote to channel 1.098 bytes, c2s@notebook.casaricci.it/127.0.0.1_5222_127.0.0.1_38465 Socket[addr=/127.0.0.1,port=38465,localport=5222]

I've tested the packet with Deflater, compressed size should be 1054 bytes, however only 1024 bytes get through.

What do you think?

Daniele Ricci commented 10 years ago

I found the cause of the issue.

In ZLibWrapper.compress, this loop:

while ( !compresser.needsInput()) {
  result_arr = deflate(result_arr);
}

is executed just once (accumulating 512 bytes of compressed data). After that, you can find this:

result_arr = deflate(result_arr);

which puts another 512 bytes to the output buffer. But then nothing. The remaining 30 bytes are lost. Well, not forever though: they will be sent with the next packet.

Daniele Ricci commented 10 years ago

I also noticed that level parameter on ZLibIO constructor is ignored.

Artur Hefczyc commented 10 years ago

Daniele, thank you for reporting the problem and providing all the details.

Andrzej, please take a look at it.

Andrzej Wójcik (Tigase) commented 10 years ago

I fixed issue by changing implementation of deflate method of ZLibWrapper to resize output buffer until whole compressed data will fix output buffer.

Artur Hefczyc commented 10 years ago

Andrzej, I am sure you did this, but checking just in case...

As you say the buffer would resize until whole compressed data fix into the buffer, I assume there is some max size set? We need this to prevent OOM.

Andrzej Wójcik (Tigase) commented 10 years ago

This resize is done only for buffer of data which are after compression but before they are written to socket, so there is no need for protection as this compressed data is in fact serialized and compressed stanza which needs to be send by server and not received by server. Also this output buffer is just array of bytes and is not cached anywhere so it will be released when data is sent by server.

Artur Hefczyc commented 10 years ago

Ok, thank you for explanation.

Type	Bug
Priority	Major
Assignee	Artur Hefczyc
RedmineID	2632
Spent time	18h

Issue Votes (0)

Watchers (0)

Reference

tigase/_server/server-core#420