IM Gateway 1.1.0 Beta

here is one login with only 2 msn contacts. for every msn contact i get :

1 roster update

1 unavailable (sometimes it’'s like the other 2 status messages)

2 status messages (always identical) - only for online contacts

i have one user that has unbelievable amount of msn contacts (~ 1000). and there are sometimes about ~3000 packets send in only 1/2 minute (1 MB traffic). and the most of that is not really needed.

i understand that the roster update is being send to the client, because something could have changed sine the last login, but the status message are annoying. also it would be a nice feature to turn of this roster updates to save bandwith on mobiles. the correct roster will be sent anyway on the next login.

these log i have stripped from my internal test-server. but the behavior is the same on the live environment.

2007.06.04 20:09:47 <?xml version=''1.0''?>
2007.06.04 20:09:47 <stream:stream xmlns:stream=''http://etherx.jabber.org/streams'' xmlns=''jabber:client'' to=''test.im'' xml:lang=''de''>
2007.06.04 20:09:47 <?xml version=''1.0'' encoding=''UTF-8''?><stream:stream xmlns:stream="http://etherx.jabber.org/streams" xmlns="jabber:client" from="192.168.11.159" id="ur1evd4d0545a" xml:lang="de"></stream:stream>
2007.06.04 20:09:47 <iq id="10" type="set" to="test.im"><query xmlns="jabber:iq:auth"><username>666763076977</username><password>xxx</password></query></iq>
2007.06.04 20:09:47 <iq type="result" id="10" from="test.im" to="666763076977@test.im"></iq>
2007.06.04 20:09:47 <iq id="11" type="get"><query xmlns="jabber:iq:roster"></query></iq>
2007.06.04 20:09:47 <presence></presence>
2007.06.04 20:09:47 <iq type="result" id="11" to="666763076977@test.im"><query xmlns="jabber:iq:roster"><item jid="yahoo.test.im" name="Yahoo! Transport" subscription="both"><group>Transports</group></item>
<item jid="notz99@yahoo.test.im" name="notz99" subscription="to"></item><item jid="666766688669@test.im" name="mortn" ask="subscribe" subscription="none"></item>
<item jid="666766688650@test.im" name="mahatma" subscription="both"></item><item jid="666766688781@test.im" name="markus" subscription="both"></item><item jid="666763588076@test.im" name="Murph" subscription="both"></item>
<item jid="msn.test.im" name="MSN Transport" subscription="both"><group>Transports</group></item><item jid="666763076976@test.im" name="notz77" subscription="both"></item>
<item jid="tina94\40test.at@msn.test.im" name="tina" subscription="to"></item><item jid="notz\40test.at@msn.test.im" name="notz@test.at" subscription="to"></item>
<item jid="666769080712@test.im" name="test" ask="subscribe" subscription="none"></item></query></iq>
2007.06.04 20:09:48 <iq type="set" id="262-420" to="666763076977@test.im"><query xmlns="jabber:iq:roster"><item jid="notz99@yahoo.test.im" name="notz99" subscription="to"></item></query></iq>
2007.06.04 20:09:48 <presence to="666763076977@test.im" from="notz99@yahoo.test.im" type="unavailable"></presence>
2007.06.04 20:09:48 <presence to="666763076977@test.im" from="yahoo.test.im"></presence>
2007.06.04 20:09:48 <iq type="set" id="408-421" to="666763076977@test.im"><query xmlns="jabber:iq:roster"><item jid="notz99@yahoo.test.im" name="notz99" subscription="to"></item></query></iq>
2007.06.04 20:09:48 <presence to="666763076977@test.im" from="notz99@yahoo.test.im" type="unavailable"></presence>
2007.06.04 20:09:52 <presence to="666763076977@test.im" from="msn.test.im"></presence>
2007.06.04 20:09:53 <presence to="666763076977@test.im" from="notz\40test.at@msn.test.im"><status></status></presence>
2007.06.04 20:09:53 <presence to="666763076977@test.im" from="notz\40test.at@msn.test.im"><status></status></presence>
2007.06.04 20:09:53 <presence to="666763076977@test.im" from="tina94\40test.at@msn.test.im"><show>away</show><status></status></presence>
2007.06.04 20:09:53 <presence to="666763076977@test.im" from="tina94\40test.at@msn.test.im"><show>away</show><status></status></presence>
2007.06.04 20:09:53 <iq type="set" id="189-422" to="666763076977@test.im"><query xmlns="jabber:iq:roster"><item jid="tina94\40test.at@msn.test.im" name="tina" subscription="to"></item></query></iq>
2007.06.04 20:09:53 <iq type="set" id="440-423" to="666763076977@test.im"><query xmlns="jabber:iq:roster"><item jid="notz\40test.at@msn.test.im" name="notz@test.at" subscription="to"></item></query></iq>
2007.06.04 20:09:53 <presence to="666763076977@test.im" from="tina94\40test.at@msn.test.im"><show>away</show></presence>
2007.06.04 20:09:53 <presence to="666763076977@test.im" from="notz\40test.at@msn.test.im"></presence>

for icq contacts i get:

1 roster update

1 status message

another NPE i got with the last version on this thread:

2007.06.05 00:02:50 [org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.java:411)] Exception while processing packet: java.lang.NullPointerException
  at org.jivesoftware.openfire.gateway.protocols.msn.MSNSession.logIn(MSNSession.java:118)
  at org.jivesoftware.openfire.gateway.protocols.msn.MSNTransport.registrationLoggedIn(MSNTransport.java:89)
  at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.java:324)
  at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.java:166)
  at org.jivesoftware.openfire.component.InternalComponentManager$RoutableComponent.process(InternalComponentManager.java:490)
  at org.jivesoftware.openfire.roster.Roster.broadcastPresence(Roster.java:590)
  at org.jivesoftware.openfire.handler.PresenceUpdateHandler.broadcastUpdate(PresenceUpdateHandler.java:258)
  at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:100)
  at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:88)
  at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateHandler.java:151)
  at org.jivesoftware.openfire.PresenceRouter.handle(PresenceRouter.java:123)
  at org.jivesoftware.openfire.PresenceRouter.route(PresenceRouter.java:69)
  at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:75)
  at org.jivesoftware.openfire.SessionPacketRouter.route(SessionPacketRouter.java:134)
  at org.jivesoftware.openfire.SessionPacketRouter.route(SessionPacketRouter.java:73)
  at org.jivesoftware.openfire.multiplex.MultiplexerPacketHandler.route(MultiplexerPacketHandler.java:164)
  at org.jivesoftware.openfire.net.MultiplexerStanzaHandler.processRoute(MultiplexerStanzaHandler.java:89)
  at org.jivesoftware.openfire.net.MultiplexerStanzaHandler.processUnknowPacket(MultiplexerStanzaHandler.java:96)
  at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:258)
  at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)
  at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:132)
  at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:703)
  at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
  at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:54)
  at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
  at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:62)
  at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:200)
  at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:362)
  at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:54)
  at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:800)
  at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:266)
  at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:326)
  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)

GATE-235 =)

Hi notz, these look like logs from your client, not from openfire. Can I get a copy of the debug logs from the server itself? I’‘ve got a grande scheme to revamp the contact list handling overall, but I’‘m generally curious about why there’‘s so many multiples. I can’'t tell “why” from these logs. =)

GATE-234

  • PLEASE increase priority of that problem, ICQ is most popular messenger, and only that bug prevent start new Openfire server…

i have now debugged the current trunk version for my problems:

1.) roster update

i see that you already check if something have changed and only send the update if something has changed, but for me the groups always change, so there have to be something wrong on that check

BaseTransport.java

List<String> curgroups = gwitem.getGroups();
                if (curgroups != groups) {
                    try {
                        gwitem.setGroups(groups);
                        changed = true;
                        Log.info("update roster item: group changed - " + contactjid);
                    }
                    catch (Exception ee) {
                        // Oooookay, ignore then.
                    }
                }

2.) why we need the initial presences on msn transport ? i don’'t think that they are nedded

3.) this function is called twice in the MSNListener on login for online contacts:

public void contactStatusChanged(MsnMessenger messenger, MsnContact friend) {

so there is one initial presence, and two times these message where friend.getStatus() is both times the same

this code change resolves the problem no. 1 for me:

List<String> curgroups = gwitem.getGroups();
if ((groups == null && curgroups.size() != 0) || (groups != null && !curgroups.containsAll(groups))) {
.
.
}

the problem is that you match an empty list against an null value or match to lists aigainst each other, what also is not working correct.

The priority really doesn’‘t make a difference in how I approach the issues. ICQ is still listed as an unstable transport for now anyway. There’‘s still a lot of work that’‘ll need to be done to it before I’'ll be moving it to stable.

Hrm. Yes that’‘s definitely a bad check. Thanks for looking into that! I’'ll look at it later today. Thanks for the patch you posted in a different reply!

2.) why we need the initial presences on msn transport ? i don’'t think that they are nedded

Well I can tell you that when I -didn’‘t- do them, people would complain. You’‘ll come online and folk who have been online for hours won’‘t show up until their presence changes. Some folk’‘s clients send presence updates a -lot- so it appears like you get an initial presence from them when you are really getting a change. If that behavior has changed I’'m certainly willing to entertain not doing the initial settings. Other protocols behave differently from this. OSCAR, for example, gives you your buddy list and then you must wait for status notifications just like any other one. Much more siimilar in behavior to XMPP if you ask me. By logging in you are effectively “precense probing” everyone. I like that behavior a lot better.

3.) this function is called twice in the MSNListener on login for online contacts:

public void contactStatusChanged(MsnMessenger messenger, MsnContact friend) {

Interesting. I wonder why it’‘s called twice? That’‘s supposed to be reactionary. Bah. Well the big thing I’‘m planning on doing is to rework the contact handling entirely. Instead of sending contact statuses on the fly, I’'m going to store them, and only send when something has changed.

notz wrote:
so there is one initial presence, and two times these message where friend.getStatus() is both times the same

i have now debugged the current trunk version for my problems:

1.) roster update

i see that you already check if something have changed and only send the update if something has changed, but for me the groups always change, so there have to be something wrong on that check

For references, GATE-236

your last changeset didn’'t resolve the problem correct

http://www.igniterealtime.org/fisheye/browse/svn-org/gateway/branches/transport_ xmpp/src/java/org/jivesoftware/openfire/gateway/BaseTransport.java?r1=8455&r2=84 65

curgroups can be an empty list

but groups will be null if their is no entry

and both are the same and should not trigger the changed flag

Well, the oddest thing. This morning I went to make sure I was still having the problem before I posted and it appears to be gone (rather randomly because I didn’‘t change anything). Just for information though I’'m going to enable the debug logs so if the problem reoccurs I can send a copy of them.

OS Version: Gentoo Linux

Java version: 1.5.0_11 Sun Microsystems Inc

Openfire version 3.3.1

I haven’'t run any versions earlier than this current beta.

Client: Psi 0.10

I wasn’'t logged in from multiple resources when the problem occurred.

Thanks,

Chad

notz wrote:

your last changeset didn’'t resolve the problem correct

http://www.igniterealtime.org/fisheye/browse/svn-org/gateway/branches/transport_ xmpp/src/java/org/jivesoftware/openfire/gateway/BaseTransport.java?r1=8455&r2=84 65

curgroups can be an empty list

but groups will be null if their is no entry

and both are the same and should not trigger the changed flag

Hrm. Yes I see your point. I originally thought was just going to make groups -be- an empty list if it was null, cut down on the checks. Lemme think through how best I want to do it. Thanks!

bgmncwj wrote:

Well, the oddest thing. This morning I went to make sure I was still having the problem before I posted and it appears to be gone (rather randomly because I didn’‘t change anything). Just for information though I’'m going to enable the debug logs so if the problem reoccurs I can send a copy of them.

OS Version: Gentoo Linux

Java version: 1.5.0_11 Sun Microsystems Inc

Openfire version 3.3.1

I haven’'t run any versions earlier than this current beta.

Client: Psi 0.10

I wasn’'t logged in from multiple resources when the problem occurred.

Thanks,

Chad

Did you happen to restart your server recently?

jadestorm wrote:

Did you happen to restart your server recently?

Nope, I mean I literally did nothing. :smiley: After I posted my message yesterday I walked away from the system till this morning and everything was working great again. Uptime for Openfire is around 12 days right now.

–Chad

LOL what the crap? well… ok. If it happens again let me know. =) Thanks!

Ive found that most of the time when i login, i will get a popup about yahoo users requesting authorization. These users were people i blocked years ago on yahoo. I deny the request and uncheck the box to add them to my roster in spark but they continue to popup as authorization requests on login.

Interesting. I tend to get that from a couple of contacts who are supposed to be on my list. GATE-239

Great realse!. Thank you. The status message now works great.

I noticed that the XMPP/Google Talk gateway ticked is closed and we can expect this to be in the 1.1.0 release. Will there be another beta, so we can test this before the release.

To be honest, I can’'t wait.