Trouble with sending messages in MUC

Vitaly1 · December 12, 2011, 11:41pm

Hi, All!

I have very strange situation with conversation in Multi-User Chat on my Openfire. That’s as follows:

There is created room (trying to create with great number of different settings - all the same). When someone sends message, then only each second one is received by server. Paradoxically, but that is. The first message is not accepted, the second one is accepted, the third - not accepted, the fourth - accepted and so on…

There is logs from the Openfire in the debug mode and from Miranda.

The First message.

Client (Miranda)

[11:20:03 JABBER_1] Deflate: Z_OK
[11:20:03 (NULL)] (00000000:0) Data sent
00000000: 17 03 01 00-30 36 25 E9-70 92 02 1D-54 2B 26 FE …06%�p�…T+&�
00000010: F6 F2 88 9D-F5 3F 21 BC-4E 28 00 8C-EE 6D 5D A5 ��?!�N(.��m]�
00000020: F0 84 C7 49-5A 04 CA 8A-60 07 D1 54-6B C0 72 40 ��IZ.ʊ`.�Tk�r@
00000030: 32 86 DC 94-9F 2�ܔ�
[11:20:03 JABBER_1] (ZLIB) Data sent
1qwe1
===OUT: 85(16) bytes

Server (Openfire)

2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Data Read: org.apache.mina.filter.support.SSLHandler@3de5627c (HeapBuffer[pos=0 lim=53 cap=64: 17 03 01 00 30 36 25 E9 70 92 02 1D 54 2B 26 FE F6 F2 88 9D F5 3F 21 BC 4E 28 00 8C EE 6D 5D A5 F0 84 C7 49 5A 04 CA 8A 60 07 D1 54 6B C0 72 40 32 86 DC 94 9F])
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] unwrap()
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] inNetBuffer: java.nio.DirectByteBuffer[pos=0 lim=53 cap=16665]
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] appBuffer: java.nio.DirectByteBuffer[pos=0 lim=33330 cap=33330]
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Unwrap res:Status = OK HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 53 bytesProduced = 16
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] inNetBuffer: java.nio.DirectByteBuffer[pos=53 lim=53 cap=16665]
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] appBuffer: java.nio.DirectByteBuffer[pos=16 lim=33330 cap=33330]
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Unwrap res:Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 0 bytesProduced = 0
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] appBuffer: java.nio.DirectByteBuffer[pos=0 lim=16 cap=33330]
2011.11.28 11:20:03 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] app data read: HeapBuffer[pos=0 lim=16 cap=16: A2 30 28 0D 81 61 69 88 11 98 00 00 00 00 FF FF] (A2 30 28 0D 81 61 69 88 11 98 00 00 00 00 FF FF)
2011.11.28 11:20:03 org.apache.mina.filter.executor.ExecutorFilter - Launching thread for /192.168.1.3:50488
2011.11.28 11:20:03 org.apache.mina.filter.executor.ExecutorFilter - Exiting since queue is empty for /192.168.1.3:50488

The Second message.

Client

[11:20:08 JABBER_1] Deflate: Z_OK
[11:20:08 (NULL)] (00000000:0) Data sent
00000000: 17 03 01 00-30 7E 71 82-BB 78 01 27-C8 8C 0E C3 …0~q��x.'Ȍ.�
00000010: 02 F2 F9 D3-00 BF C0 50-0D 7C F5 B0-5A D0 7A 8A .��.��P.|��Z�z�
00000020: 5F 79 97 26-86 0A ED 00-FE 78 3D E2-88 36 82 DC _y�&�.�.�x=�6��
00000030: DA D5 FB F2-E0 ��
[11:20:08 JABBER_1] (ZLIB) Data sent
2qwe2
===OUT: 85(15) bytes
[11:20:08 (NULL)] (00000000:0) Data received
00000000: 17 03 01 00-30 7D 1D 24-00 0A 72 80-5C 2A EC B6 …0}.$…r�*�
00000010: F6 F0 5E D9-28 53 45 B0-EC 18 29 90-47 76 C4 7B ��^�(SE��.)�Gv�{
00000020: FD 0D 75 3A-90 CC 96 B9-31 48 88 AC-6B 27 99 02 �.u:�̖�1H��k’�.
00000030: AC C2 8B 3A-5E ��:^
[11:20:08 (NULL)] (00000000:0) Data received
00000000: 1A B4 11 65-04 8C 29 23-8C A8 02 00-00 00 FF FF .�.e.�)#��…��
[11:20:08 JABBER_1] Inflate: Z_OK
[11:20:08 JABBER_1] (ZLIB) Data received
2qwe2
===IN: 175(16) bytes
[11:20:08 JABBER_1] recvResult = 175
[11:20:08 JABBER_1] bytesParsed = 175
[11:20:08 JABBER_1] Handling message from call-center@jbr2.mydomain.loc/��& #65533; �� &#65533 ;��

Server

2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Data Read: org.apache.mina.filter.support.SSLHandler@3de5627c (HeapBuffer[pos=0 lim=53 cap=64: 17 03 01 00 30 7E 71 82 BB 78 01 27 C8 8C 0E C3 02 F2 F9 D3 00 BF C0 50 0D 7C F5 B0 5A D0 7A 8A 5F 79 97 26 86 0A ED 00 FE 78 3D E2 88 36 82 DC DA D5 FB F2 E0])
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] unwrap()
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] inNetBuffer: java.nio.DirectByteBuffer[pos=0 lim=53 cap=16665]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] appBuffer: java.nio.DirectByteBuffer[pos=0 lim=33330 cap=33330]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Unwrap res:Status = OK HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 53 bytesProduced = 15
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] inNetBuffer: java.nio.DirectByteBuffer[pos=53 lim=53 cap=16665]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] appBuffer: java.nio.DirectByteBuffer[pos=15 lim=33330 cap=33330]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Unwrap res:Status = BUFFER_UNDERFLOW HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 0 bytesProduced = 0
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] appBuffer: java.nio.DirectByteBuffer[pos=0 lim=15 cap=33330]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] app data read: HeapBuffer[pos=0 lim=15 cap=15: A2 D0 50 23 A0 A1 46 18 86 02 00 00 00 FF FF] (A2 D0 50 23 A0 A1 46 18 86 02 00 00 00 FF FF)
2011.11.28 11:20:08 org.apache.mina.filter.executor.ExecutorFilter - Launching thread for /192.168.1.3:50488
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50523] Filtered Write: org.apache.mina.filter.support.SSLHandler@1ea4daa3
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50523] encrypt: HeapBuffer[pos=0 lim=16 cap=184: 1A 94 0E 35 02 BA D4 08 C3 A9 00 00 00 00 FF FF]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50523] Wrap res:Status = OK HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 16 bytesProduced = 53
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50523] encrypted buf: HeapBuffer[pos=0 lim=53 cap=53: 17 03 01 00 30 AF 00 41 77 6D CE CD D7 86 C3 B2 27 FC 05 72 48 A4 8B 4B 92 43 49 B5 6F D6 F6 F7 01 0D 27 0B 72 F0 72 CE E9 93 F8 3F 00 36 1D 50 97 B6 32 90 90]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Filtered Write: org.apache.mina.filter.support.SSLHandler@3de5627c
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] encrypt: HeapBuffer[pos=0 lim=16 cap=188: 1A B4 11 65 04 8C 29 23 8C A8 02 00 00 00 FF FF]
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] Wrap res:Status = OK HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 16 bytesProduced = 53
2011.11.28 11:20:08 org.jivesoftware.openfire.nio.ClientConnectionHandler - [/192.168.1.3:50488] encrypted buf: HeapBuffer[pos=0 lim=53 cap=53: 17 03 01 00 30 7D 1D 24 00 0A 72 80 5C 2A EC B6 F6 F0 5E D9 28 53 45 B0 EC 18 29 90 47 76 C4 7B FD 0D 75 3A 90 CC 96 B9 31 48 88 AC 6B 27 99 02 AC C2 8B 3A 5E]
2011.11.28 11:20:08 org.apache.mina.filter.executor.ExecutorFilter - Exiting since queue is empty for /192.168.1.3:50488
2011.11.28 11:20:08 org.apache.mina.filter.executor.ExecutorFilter - Launching thread for /192.168.1.3:50523
2011.11.28 11:20:08 org.apache.mina.filter.executor.ExecutorFilter - Exiting since queue is empty for /192.168.1.3:50523
2011.11.28 11:20:08 org.apache.mina.filter.executor.ExecutorFilter - Launching thread for /192.168.1.3:50488
2011.11.28 11:20:08 org.apache.mina.filter.executor.ExecutorFilter - Exiting since queue is empty for /192.168.1.3:50488

And more odd is the same as the First message, but even is as the Second message.

I have Openfire 3.7.1 (upgraded from 3.7.0) on Debian Squeeze, Miranda 0.9.25 (but trying on the Pidgin 2.10.0 and MUC wasn’t work there generally) on Windows XP and Seven, Active Directiory on Windows 2008 Server, authentication over GSSAPI (SSO).

Can anyone help me?

wroot · December 13, 2011, 7:17am

How about some other client, like Spark?

Vitaly1 · December 13, 2011, 11:19am

Can’t use Spark with SSO as I described earlier http://community.igniterealtime.org/message/215762 and dont know anymore clients supported SSO.

Vitaly1 · December 19, 2011, 5:58am

I asked the second question in this community and not received an answer or something a little useful to any of them. Are my questions so difficult? Why can not the developers answer about software, which they develope?

Using Spark 2.6.3 under Win7 without SSO gave the same results. Only even messages is delivered by Openfire.

Any idea?

wroot · December 19, 2011, 7:50am

SSO questions is more complex indeed. At least for me, as i’m not using it. There are almost no active developers since Jive has opensourced this project, so complex questions don’t get many answers.

Vitaly1 · December 19, 2011, 2:56pm

But problem with MUC remains without SSO (using Spark for example).

wroot · December 19, 2011, 7:18pm

I can’t reproduce this with Openfire 3.7.1 and Spark (one of the latest 2.7.0 builds) or say Exodus. I see every message sent to a chat room. I can’t read those error logs, so i can’t say what could be happening. Any plugins you have installed on the server? Like Content Filter or Packet Filter?