Receiving new Spark message opens window but doesn't display message

I’ve been using pidgin all day and I’ve received every message sent to me. So maybe this is actually a Spark issue? Or at least an issue related to how Openfire and Spark interact. That makes sense to me considering the fact that the Spark debugger knew it received the message, Spark just somehow wasn’t able to display it.

Ok, i have moved the ticket and this discussion to Spark sections https://issues.igniterealtime.org/browse/SPARK-1794

You debug example doesn’t have a body part of the message. Looks strange. Like it is just a chatstate update (typing, etc.).

I have the same issue with 4.0.3 / 2.8 - I can see the message in the debug window but not on spark’s chat window. Further chats within the same session are normal. This does not happens every time.

The message that you provided is not an actual chat message, it is bit of metadata, that’s used to signal the current state of the peer user (it is used to display messages like “user is typing…”, things like that).

Can you, with certainty, tell if the other user was sending you an actual message (as in, composed text)? If there’s a bug in Spark where it would pop up a new chat window when it receives a chat state change, it would look as if you missed a message - perhaps that message was not sent in the first place?

Guus,

In my environment (4.0.3 / 2.8 both on Ubnutu) I can see the message in the logs but the chat window in spark shows nothing. So, essentially, I miss the first message.

Yes, there was definitely a message sent, it just didn’t show up in my spark. The message was logged in openfire.

Ok, that’s clear. And by “logged in Openfire”, you mean what exactly? Where do you find the message ‘in Openfire’?

Also: using the Spark/Smack debug window, do you see the (text) message at all (even if it does not appear in a chat window, I wonder if the data arrives at your computer)?

If I search the openfire archives, it finds the message that was sent to me that I didn’t receive.

I received 6 notifications identical to the one I put in my earlier response for the message that opened my chat window and made it flash but that never showed up. I’m not sure where in the debug window you want me to look. I’ve been working in Pidgin for the last few days and have received every message sent to me. I’ll switch back to Spark and see what kind of debug logs I can generate.

As i’ve said it should be in Raw Packets Received. But there should be actual message text in the packets. If it is not there, then the message is not actually received by Spark.

Ok, I’m back on Spark and I’ll post back once it happens again.

To start the debugger, select “advanced” on the login screen (where you fill out your username/password), then make sure that “start debugger on startup” is checked. It will give you a new screen with lots of debugging information after you log in.

You’ve already mentioned that the message shows up in the message archive on the Openfire side, but it’s unclear to me if you looked at the Openfire log files. Perhaps a warning or error is logged there, that indicates why a packet is not processed properly.

The easiest way to look at the Openfire logs is by looking at the file “all.log” in the directory “logs” of the installation folder of Openfire. You can also view the logs via the Openfire admin console, but for a reason that I never quite understood, the log files there is separated in four distinct tabs (each for a different severity).

Here is everything logged by Openfire around the time of one of these lost/missed messages:

2016.08.30 10:28:41 WARN [pool-29-thread-4]: org.jivesoftware.openfire.net.SocketUtil - Unable to create a socket connection to XMPP domain 'Domain' using remote host: Domain:5269. Cause: Connection refused: connect (a full stacktrace is logged on debug level)
2016.08.30 10:28:41 WARN [pool-29-thread-4]: org.jivesoftware.openfire.net.SocketUtil - Unable to create a socket connection to XMPP domain 'Domain': Unable to connect to any of its remote hosts.
2016.08.30 10:28:41 INFO [pool-29-thread-4]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Create outgoing session for: OpenFireServer to Domain] - Unable to create new session: Cannot create a plain socket connection with any applicable remote host.
2016.08.30 10:28:41 WARN [pool-29-thread-4]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'OpenFireServer' to remote domain: 'Domain'] - Unable to authenticate: Fail to create new session.
2016.08.30 10:30:48 WARN [pool-29-thread-5]: org.jivesoftware.openfire.net.SocketUtil - Unable to create a socket connection to XMPP domain 'Domain' using remote host: Domain:5269. Cause: Connection refused: connect (a full stacktrace is logged on debug level)
2016.08.30 10:30:48 WARN [pool-29-thread-5]: org.jivesoftware.openfire.net.SocketUtil - Unable to create a socket connection to XMPP domain 'Domain': Unable to connect to any of its remote hosts.
2016.08.30 10:30:48 INFO [pool-29-thread-5]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Create outgoing session for: OpenFireServer to Domain] - Unable to create new session: Cannot create a plain socket connection with any applicable remote host.
2016.08.30 10:30:48 WARN [pool-29-thread-5]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'OpenFireServer' to remote domain: 'Domain'] - Unable to authenticate: Fail to create new session.
2016.08.30 10:33:49 WARN [pool-29-thread-1]: org.jivesoftware.openfire.net.SocketUtil - Unable to create a socket connection to XMPP domain 'Domain' using remote host: Domain:5269. Cause: Connection refused: connect (a full stacktrace is logged on debug level)
2016.08.30 10:33:49 WARN [pool-29-thread-1]: org.jivesoftware.openfire.net.SocketUtil - Unable to create a socket connection to XMPP domain 'Domain': Unable to connect to any of its remote hosts.
2016.08.30 10:33:49 INFO [pool-29-thread-1]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Create outgoing session for: OpenFireServer to Domain] - Unable to create new session: Cannot create a plain socket connection with any applicable remote host.
2016.08.30 10:33:49 WARN [pool-29-thread-1]: org.jivesoftware.openfire.session.LocalOutgoingServerSession[Authenticate local domain: 'OpenFireServer' to remote domain: 'Domain'] - Unable to authenticate: Fail to create new session.

Guus, correct me if I’m wrong, but that looks like a DNS and S2S issue. my guess is the client is using a cname or something as “server” address, instead of the xmpp domain, which is prob causing the issue

Here are all of the raw packets received today when I received a message from a user, Jill, that didn’t display although the chat window opened and flashed. You can see in the data below that the message itself did come in to spark, it just wasn’t displayed.

<message to="gretchen@OpenfireServer" id="8h9tm-613" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><thread>eSYGso</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="8h9tm-614" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><thread>eSYGso</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="8h9tm-615" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><thread>eSYGso</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="8h9tm-616" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><thread>eSYGso</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="8h9tm-617" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><body>i am having some printer issues - could you pls take a look?</body><thread>eSYGso</thread><x xmlns="jabber:x:event"><offline/><composing/></x><active xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="8h9tm-619" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><thread>eSYGso</thread><paused xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="8h9tm-620" type="chat" from="jill@OpenfireServer/Spark 2.6.3"><thread>eSYGso</thread><gone xmlns="http://jabber.org/protocol/chatstates"/></message>
<iq type="get" id="89-27224" from="OpenfireServer" to="gretchen@OpenfireServer/Spark 2.6.3"><ping xmlns="urn:xmpp:ping"/></iq>

Here’s another where the message didn’t show in my Spark window, but it opened and flashed.

<iq to="gretchen@OpenfireServer/Spark 2.6.3" id="jy7qe-24829" type="get" from="glenda@OpenfireServer/Spark 2.6.3"><query xmlns="jabber:iq:last"/></iq>
<message to="gretchen@OpenfireServer" id="jy7qe-24831" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<presence id="n5D6o-1128" from="rob@OpenfireServer/Spark 2.6.3" to="gretchen@OpenfireServer"><status>Away</status><priority>0</priority><show>away</show><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://www.igniterealtime.org/projects/smack" ver="TJuVIXqTCVfJSthaPu4MtTbaf9A="/></presence>
<message to="gretchen@OpenfireServer" id="jy7qe-24833" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24834" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24835" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><paused xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24836" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24837" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24838" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24839" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24840" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24841" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24842" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><paused xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24843" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24844" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><composing xmlns="http://jabber.org/protocol/chatstates"/></message>
<message to="gretchen@OpenfireServer" id="jy7qe-24845" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><body>Hi Gretchen, i am working at home, i laserfiche kicked me off yesterday and now today again. Do you know if we are having problems?</body><thread>Ydl73u</thread><x xmlns="jabber:x:event"><offline/><composing/></x><active xmlns="http://jabber.org/protocol/chatstates"/></message>
<presence id="qXk1H-10" from="crystal@OpenfireServer/Spark 2.6.3" to="gretchen@OpenfireServer"><status>Online</status><priority>1</priority><c xmlns="http://jabber.org/protocol/caps" hash="sha-1" node="http://www.igniterealtime.org/projects/smack" ver="TJuVIXqTCVfJSthaPu4MtTbaf9A="/></presence>
<message to="gretchen@OpenfireServer" id="jy7qe-24848" type="chat" from="glenda@OpenfireServer/Spark 2.6.3"><thread>Ydl73u</thread><paused xmlns="http://jabber.org/protocol/chatstates"/></message>

Although I doubt that it relates to the issue at hand, each of these log messages are all relate to pretty much the same thing: Your Openfire (which is running the XMPP domain “OpenFireServer”), is trying, and failing, to create a connection to another server (might be yours, might be someone else’s, might not exist at all) that is running the XMPP domain “Domain”.

A common cause for your Openfire to try and connect to another server is to allow users from both networks to talk to each-other. Assuming that your username is “gretchen” (which would make your JID “gretchen@OpenFireServer”), it is very possible that you want to chat with your friend named “oliver” that’s on another XMPP network, named “Domain” (Oliver’s JID would be “oliver@Domain”). You could have done so by adding “oliver@Domain” to your contact list, after which your domain will attempt to make contact with Oliver’s domain. These attempts are what we see failing in the log file that you provided.

Note that it is possible that you tried to add a contact to your contact list, but used an incorrect JID to do so. For instance, Oliver could have an account on the same XMPP domain as yours (eg: “oliver@OpenFireServer”), but you accidentally used “oliver@Domain” instead. Even if the XMPP domain “Domain” does not exist, or is currently not reachable, your domain will attempt to contact it.

The names of both XMPP domains are suspicious: “OpenFireServer” and “Domain” look odd. Did you search/replace these values before you posted the log files here? If not, your setup might need to be looked at - although you can probably make things work with these names, odd values like this can lead to confusion, and thus, problems.

Ah, this is very helpful. This confirms that it is indeed an issue in Spark, not Openfire.

I was somewhat able to reproduce the problem. Spark is very extensible in nature. All kinds of plugins can add functionality. I’ve found that Spark would stop processing messages completely, if one of the ‘add-ons’ would throw an unexpected problem. I’ve addressed this issue here: https://issues.igniterealtime.org/browse/SPARK-1798 and provided a fix here: SPARK-1798: Gracefully handle exceptions from event listeners. by guusdk · Pull Request #215 · igniterealtime/Spark · Gi…

With the fix for this issue, the root cause of the problem won’t be fixed (I don’t know what it is), but the effect would now be isolated to that ‘add-on’. It would no longer prevent further processing of the message.

There’s a good chance that this will ‘fix’ your problem (not being able to see an incoming message). As a side-effect, the root cause should now be logged in the error logs of Spark. That will allow us to address that too.

1 Like

I did a search and replace to replace the name of the server that Open Fire is installed on to OpenFireServer, but Domain is just how it is in the logs. We have only one domain and our openfire server shouldn’t be trying to contact another server or domain. I’ll have to look into that to figure out what is going on.