Potential stream compression bug in wildfire 3.2.3

Openfire Openfire Support
1

It seems there are som interoperability problems between Wildfir 3.2.3 and the development version of Psi, if Psi enables stream compression if possible (and wildfire presents that feature).

I don’'t personally have any logs but reports about logs from the iris layer in Psi says this:

they contain private data and I cannot see any pattern

there are parts missing which results in weird data

This results in Psi disconnecting with an XML parsing error.

Older versions of Wildfire does not seem to have this problem, and same version of Psi that negotiates stream compression with other servers (in my case, a few different ejabberd) does not dosconnect with the error either.

I have not had any chance to test with another client that supports stream compression.

2

I can confirm this is happening with the beta version of psi. If anyone has pointers to what they’‘d like to see logging wise, I’'m happy to collect ''em.

PS: This can be worked around on the client by disabling “Compress Traffic (if possible)” in Account Setup -> Modify -> Connection Tab.

-Gene

Message was edited by: hoffmang

3

I rebuilt Psi with XMPP_DEBUG defined in iris/xmpp-core/stream.cpp.

I discovered this behaviour when I used Pandion (which I believe uses stream compression too):

I sign in, I get most of my roster, all contacts go offline, some contacts go online again. I believe this is the same as with Psi, except that Psi closes the connection. So, Wildfire?

4

Hey guys,

I’'m not able to reproduce the problem. I tested with:

  1. Pandion 2.5. Press F12 before logging in to see exchanged XML.

  2. Psi (Feb 7 2007). Open XML console to see exchanged XML.

  3. Latest Smack and Spark (SVN code)

In all cases compression is used and XML traffic is still flowing after compression is being used. I tested both TLS+compression and compression without TLS. Could you open the XML console in Psi / Pandion to collect XML traffic so I can see where things are halting?

In Smack/Spark we had to make a change so that compression could work with new Openfire 3.2.3. The problem was related to the way flush was being performed. The problem was not always happening since it was related to how TCP was breaking up traffic. Having said that, it is possible that we are having the same problem in Psi. Could you verify if you are using the synch_fliush method (or partial_flush)? FYI, partial_flush is deprecated and synch_flush should be used instead. That was the problem in Smack/Spark.

Regards,

– Gato

5

I had to x-out all bits that are part of a JID, yet those are not proper JIDs but messed and mixed up. As an example, a normal JID on our server looks like this: xxxxx.xxxx@jabber.domain-domain.de. I’'ll leave the dots and minus to show you where the JIS was messed up. Whereever ou see xxx there was a part of a JID!

Looking at the XML-console will not help to debug this. As aholm has stated you have to re-compile Psi to have a look at the raw xml. “I rebuilt Psi with XMPP_DEBUG defined in iris/xmpp-core/stream.cpp.” You enable client encryption on both the server as well as the client and try to login multiple times.

Message was edited by: Sven

6

I had originally tested this with psi-0.11-beta4 and can now confirm that it also occurs with psi-0.11-beta5 .

The “compress traffic” flag is a valid work around for both.

-Gene

7

Could you verify if you are using the synch_fliush method (or partial_flush)? FYI, partial_flush is deprecated and synch_flush should be used instead.

According to Remko Psi is using sync flush.

8

I still see this with Wildfire 3.2.4, but not every time. Maybe it depends on the presence of contacts in my roster?

Message was edited by: aholm

9

And also with Openfire 3.3.0… Please contact me if I can provide more logs or debug data from the Openfire side of things.

10

I also have problem with compression in Openfire 3.3.0

with PSI v0.11-beta5

I have in error log:

2007.04.24 23:29:04 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHand ler.java:109)

]

java.lang.ArrayIndexOutOfBoundsException: -2147483646

at com.jcraft.jzlib.Deflate.deflate_slow(Deflate.java:1131)

at com.jcraft.jzlib.Deflate.deflate(Deflate.java:1567)

at com.jcraft.jzlib.ZStream.deflate(ZStream.java:133)

at org.apache.mina.filter.support.Zlib.deflate(Zlib.java:176)

at org.apache.mina.filter.CompressionFilter.filterWrite(CompressionFilter.java:198 )

at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(Ab stractIoFilterChain.java:445)

at org.apache.mina.common.support.AbstractIoFilterChain.access$1400(AbstractIoFilt erChain.java:54)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(Ab stractIoFilterChain.java:824)

at org.apache.mina.filter.executor.ExecutorFilter.filterWrite(ExecutorFilter.java: 292)

at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(Ab stractIoFilterChain.java:445)

at org.apache.mina.common.support.AbstractIoFilterChain.access$1400(AbstractIoFilt erChain.java:54)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(Ab stractIoFilterChain.java:824)

at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilte r.java:227)

at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(Ab stractIoFilterChain.java:445)

at org.apache.mina.common.support.AbstractIoFilterChain.access$1400(AbstractIoFilt erChain.java:54)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(Ab stractIoFilterChain.java:824)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.filterWrite(Abs tractIoFilterChain.java:727)

at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(Ab stractIoFilterChain.java:445)

at org.apache.mina.common.support.AbstractIoFilterChain.fireFilterWrite(AbstractIo FilterChain.java:436)

at org.apache.mina.transport.socket.nio.SocketSessionImpl.write0(SocketSessionImpl .java:196)

at org.apache.mina.common.support.BaseIoSession.write(BaseIoSession.java:149)

at org.apache.mina.common.support.BaseIoSession.write(BaseIoSession.java:135)

at org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:201)

at org.jivesoftware.openfire.session.ClientSession.deliver(ClientSession.java:728)

at org.jivesoftware.openfire.session.Session.process(Session.java:281)

at org.jivesoftware.openfire.MessageRouter.route(MessageRouter.java:104)

at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:71)

at org.jivesoftware.openfire.net.SocketReader.processMessage(SocketReader.java:287 )

at org.jivesoftware.openfire.net.ServerSocketReader.access$201(ServerSocketReader. java:46)

at org.jivesoftware.openfire.net.ServerSocketReader$3.run(ServerSocketReader.java: 129)

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

at java.lang.Thread.run(Unknown Source)

with JAJC it simply thinks that compression is not possible.

11

Relevant Openfire configuration:

If I set “Client connection security, TLS method” to “optional” then I can’'t reproduce it.

If I keep it at “Required” I get it most of the time.

“Client Compression Policy” is available.

12

I still get this with 3.3.2.

Server: TLS required, Stream compression available.

Client: Force stream compression and force TLS usage.

This time I just tested with Psi, but I bet Pandion still shows the same problem.

13

Openfire 3.4.0 Alpha 2 (2007-08-29) gets same exceptions.

2007.09.10 10:45:57 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHandler.java:109)
] java.lang.ArrayIndexOutOfBoundsException
at java.lang.System.arraycopy(Native Method)
at com.jcraft.jzlib.ZStream.read_buf(ZStream.java:199)
at com.jcraft.jzlib.Deflate.fill_window(Deflate.java:983)
at com.jcraft.jzlib.Deflate.deflate_slow(Deflate.java:1120)
at com.jcraft.jzlib.Deflate.deflate(Deflate.java:1567)
at com.jcraft.jzlib.ZStream.deflate(ZStream.java:133)
at org.apache.mina.filter.support.Zlib.deflate(Zlib.java:174)
at org.apache.mina.filter.CompressionFilter.filterWrite(CompressionFilter.java:191)
at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1300(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(AbstractIoFilterChain.java:658)
at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:201)
at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1300(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(AbstractIoFilterChain.java:658)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.filterWrite(AbstractIoFilterChain.java:586)
at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
at org.apache.mina.common.support.AbstractIoFilterChain.fireFilterWrite(AbstractIoFilterChain.java:355)
at org.apache.mina.transport.socket.nio.SocketSessionImpl.write0(SocketSessionImpl.java:186)
at org.apache.mina.common.support.BaseIoSession.write(BaseIoSession.java:147)
at org.apache.mina.common.support.BaseIoSession.write(BaseIoSession.java:136)
at org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:216)
at org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:754)
at org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:262)
at org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:210)
at org.jivesoftware.openfire.SessionManager.userBroadcast(SessionManager.java:972)
at org.jivesoftware.openfire.roster.Roster.broadcast(Roster.java:658)
at org.jivesoftware.openfire.roster.Roster.deleteRosterItem(Roster.java:461)
at org.jivesoftware.openfire.roster.Roster.deleteSharedUser(Roster.java:973)
at org.jivesoftware.openfire.roster.RosterManager.groupUserDeleted(RosterManager.java:683)
at org.jivesoftware.openfire.roster.RosterManager.groupUserDeleted(RosterManager.java:650)
at org.jivesoftware.openfire.roster.RosterManager.memberRemoved(RosterManager.java:445)
at org.jivesoftware.openfire.event.GroupEventDispatcher.dispatchEvent(GroupEventDispatcher.java:122)
at org.jivesoftware.openfire.group.Group$MemberCollection$1.remove(Group.java:369)
at java.util.AbstractCollection.remove(Unknown Source)
at eu.op3racional.registrationPlugin2.removeUserFromGroup(registrationPlugin2.java:200)
at org.jivesoftware.openfire.plugin.registration2.mnguser_jsp._jspService(mnguser_jsp.java:216)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:97)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.jivesoftware.openfire.container.PluginServlet.handleJSP(PluginServlet.java:228)
at org.jivesoftware.openfire.container.PluginServlet.service(PluginServlet.java:86)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:491)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1074)
at org.jivesoftware.admin.PluginFilter.doFilter(PluginFilter.java:69)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:98)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at com.opensymphony.module.sitemesh.filter.PageFilter.parsePage(PageFilter.java:118)
at com.opensymphony.module.sitemesh.filter.PageFilter.doFilter(PageFilter.java:52)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.jivesoftware.util.LocaleFilter.doFilter(LocaleFilter.java:65)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.jivesoftware.util.SetCharacterEncodingFilter.doFilter(SetCharacterEncodingFilter.java:41)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.jivesoftware.admin.PluginFilter.doFilter(PluginFilter.java:69)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.jivesoftware.admin.AuthCheckFilter.doFilter(AuthCheckFilter.java:98)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1065)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:365)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:185)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:689)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:391)
at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:146)
at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:139)
at org.mortbay.jetty.Server.handle(Server.java:285)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:457)
at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:751)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:500)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:209)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:357)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:329)
at org.mortbay.thread.BoundedThreadPool$PoolThread.run(BoundedThreadPool.java:475)

Also this:

java.lang.ArrayIndexOutOfBoundsException: -2147483646

Hm, my plugin shows up in the mess…

14

Related: http://coccinella.im/node/80

15

Can we have an official bug added then? This really needs fixing.

16

We can enjoy JM-1115 (;

I still use compression within Spark but sometimes I get kicked with a

com.jcraft.jzlib.ZStreamException: inflating: invalid stored block lengths

at com.jcraft.jzlib.ZInputStream.read(ZInputStream.java:107)

at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:264)

exception.

LG

17

I was having similar problems a month ago using 3.3.2. Please see my thread (BUG: Compression failures in 3.3.2) for more info. Thanks

18

I am having a similar problem with compression as well, so I thought I would add my stack trace to the bunch in the hopes we can get a solution figured out.

For the server, I am running Openfire 3.3.3 with TLS required and compression available.

For the client, I am running a custom client using Smack 3.04 with TLS and compression enabled.

Smack reports that it completes the connection and authentication phases successfully, but in the Smack debug window it never receives the XML data for the roster. This happens 100% of the time when Openfire first boots up, but as it warms up with subsequent logins I see it less frequently. The exception generated on the server is as follows:

java.io.IOException: Unknown error. Error code : -3 and message : unknown compression method

at org.apache.mina.filter.support.Zlib.inflate(Zlib.java:137)

at org.apache.mina.filter.CompressionFilter.messageReceived(CompressionFilter.java :159)

at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)

at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)

at org.apache.mina.filter.support.SSLHandler.flushScheduledEvents(SSLHandler.java: 275)

at org.apache.mina.filter.SSLFilter.messageReceived(SSLFilter.java:427)

at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)

at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilt erChain.java:53)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceive d(AbstractIoFilterChain.java:648)

at org.apache.mina.common.support.AbstractIoFilterChain$HeadFilter.messageReceived (AbstractIoFilterChain.java:499)

at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(Ab stractIoFilterChain.java:299)

at org.apache.mina.common.support.AbstractIoFilterChain.fireMessageReceived(Abstra ctIoFilterChain.java:293)

at org.apache.mina.transport.socket.nio.SocketIoProcessor.read(SocketIoProcessor.j ava:218)

at org.apache.mina.transport.socket.nio.SocketIoProcessor.process(SocketIoProcesso r.java:188)

at org.apache.mina.transport.socket.nio.SocketIoProcessor.access$500(SocketIoProce ssor.java:44)

at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(SocketIoProce ssor.java:471)

at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:39)

at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

at java.lang.Thread.run(Unknown Source)

Thanks,

Chris

19

so in Openfire 3.4.1 on Windows 2003

2007.11.04 19:40:03 [org.jivesoftware.openfire.nio.ConnectionHandler.exceptionCaught(ConnectionHandler.java:109)
] java.lang.ArrayIndexOutOfBoundsException: -1
     at com.jcraft.jzlib.Tree.gen_codes(Tree.java:345)
     at com.jcraft.jzlib.Tree.build_tree(Tree.java:311)
     at com.jcraft.jzlib.Deflate._tr_flush_block(Deflate.java:860)
     at com.jcraft.jzlib.Deflate.flush_block_only(Deflate.java:772)
     at com.jcraft.jzlib.Deflate.deflate_slow(Deflate.java:1226)
     at com.jcraft.jzlib.Deflate.deflate(Deflate.java:1567)
     at com.jcraft.jzlib.ZStream.deflate(ZStream.java:133)
     at org.apache.mina.filter.support.Zlib.deflate(Zlib.java:174)
     at org.apache.mina.filter.CompressionFilter.filterWrite(CompressionFilter.java:192)
     at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
     at org.apache.mina.common.support.AbstractIoFilterChain.access$1300(AbstractIoFilterChain.java:53)
     at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(AbstractIoFilterChain.java:659)
     at org.apache.mina.filter.executor.ExecutorFilter.filterWrite(ExecutorFilter.java:256)
     at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
     at org.apache.mina.common.support.AbstractIoFilterChain.access$1300(AbstractIoFilterChain.java:53)
     at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(AbstractIoFilterChain.java:659)
     at org.apache.mina.filter.codec.ProtocolCodecFilter.filterWrite(ProtocolCodecFilter.java:210)
     at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
     at org.apache.mina.common.support.AbstractIoFilterChain.access$1300(AbstractIoFilterChain.java:53)
     at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.filterWrite(AbstractIoFilterChain.java:659)
     at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.filterWrite(AbstractIoFilterChain.java:587)
     at org.apache.mina.common.support.AbstractIoFilterChain.callPreviousFilterWrite(AbstractIoFilterChain.java:361)
     at org.apache.mina.common.support.AbstractIoFilterChain.fireFilterWrite(AbstractIoFilterChain.java:355)
     at org.apache.mina.transport.socket.nio.SocketSessionImpl.write0(SocketSessionImpl.java:166)
     at org.apache.mina.common.support.BaseIoSession.write(BaseIoSession.java:177)
     at org.apache.mina.common.support.BaseIoSession.write(BaseIoSession.java:168)
     at org.jivesoftware.openfire.nio.NIOConnection.deliver(NIOConnection.java:221)
     at org.jivesoftware.openfire.session.LocalClientSession.deliver(LocalClientSession.java:754)
     at org.jivesoftware.openfire.session.LocalSession.process(LocalSession.java:262)
     at org.jivesoftware.openfire.spi.RoutingTableImpl.routePacket(RoutingTableImpl.java:211)
     at org.jivesoftware.openfire.PresenceRouter.handle(PresenceRouter.java:159)
     at org.jivesoftware.openfire.PresenceRouter.route(PresenceRouter.java:67)
     at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:75)
     at org.jivesoftware.openfire.net.SocketReader.processPresence(SocketReader.java:264)
     at org.jivesoftware.openfire.net.SocketReader.process(SocketReader.java:189)
     at org.jivesoftware.openfire.net.BlockingReadingMode.readStream(BlockingReadingMode.java:156)
     at org.jivesoftware.openfire.net.BlockingReadingMode.run(BlockingReadingMode.java:62)
     at org.jivesoftware.openfire.net.SocketReader.run(SocketReader.java:119)
     at java.lang.Thread.run(Unknown Source)

and many other errors: ArrayIndexOutOfBoundsException

On Openfire 3.4.1 on linux everything is Ok

20

And same bug is also in OpenFire 3.4.2 …

It’s not good…