powered by Jive Software

Yahoo transport problem

Hi

I moved my server and upgraded to new versions over the weekend. I am now running Openfire 3.3.2 on a Windows 2k3 server (actually WHS) with the 1.1.0 IM Gateway. Previously I was running 3.2.3 with a beta release (1.0 Beta 8 - I believe). Although the old ym transport was not considered to be stable it had proved pretty reliable for me. It required a “kick” about once a month but otherwise operated reasonable well. Statuses did not always update, etc. The new gateway seems to be having a few problems though. YM seems to stop working quite frequently. I can restart it by unticking and ticking the Yahoo Messenger entry in the settings page. It then seems to operate fine for a while. Statuses update properly, users logging on and off seem to update quickly and even typing shows up. However, after a quite a few hours without any activity, the transport seems to stop working, eg:

2007.08.14 08:03:01 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send typing notification to yahoo user.

2007.08.14 08:03:02 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send typing notification to yahoo user.

2007.08.14 08:03:05 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send message to yahoo user.

Strangely Openfire then appeared to try and connect over S2S on this occasion.

2007.08.14 08:08:08 [org.jivesoftware.openfire.session.OutgoingServerSession.createOutgoingSession( OutgoingServerSession.java:258)

] Error trying to connect to remote server: yahoo.rectoryhouse.net(DNS lookup: yahoo.rectoryhouse.net:5269)

java.net.UnknownHostException: yahoo.rectoryhouse.net

at java.net.PlainSocketImpl.connect(Unknown Source)

at java.net.SocksSocketImpl.connect(Unknown Source)

at java.net.Socket.connect(Unknown Source)

at org.jivesoftware.openfire.session.OutgoingServerSession.createOutgoingSession(O utgoingServerSession.java:253)

at org.jivesoftware.openfire.session.OutgoingServerSession.authenticateDomain(Outg oingServerSession.java:142)

at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.sendPa cket(OutgoingSessionPromise.java:199)

at org.jivesoftware.openfire.server.OutgoingSessionPromise$PacketsProcessor.run(Ou tgoingSessionPromise.java:184)

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)

Any ideas as to what the problem might be or what I can do to help identify the cause. I am using Pandion as a client.

Thank you for all the effort you have put into the Gateway it is a really valuable plugin.

Best Regards

David

Wait, are you telling me that it was working better in 1.1.0 Beta 8? Because nothing really changed with the Yahoo transport between Beta 8 and release. I don’t recall when I shifted it from unstable to stable but literally that was all I did, shift it’s location on the page. Color me confused! The s2s indicator is probably some event that occured when you “cycled” the transport … ie the transport released yahoo.yourserver, something tried to contact it, and it was consider not owned by anyone at that point.

I never understand why I don’t see things like this come up. I mean yes I’m the only one using it on my server, but scenarios like this seem like they’d show up anyway.

Also that log entry isn’t all that useful is it. ;D There’s probably an exception I ought to be displaying that’s occuring that might tell more about what’s going on. (though I suspect it’s a dead connection for whatever reason)

Of course, the other day I literally could not connect to Yahoo all day … even from a real Yahoo client. That said I didn’t see any issues yesterday. =/

Hi

No it was actually more stable for me on 1.0 Beta 8 (I think) - the old unstable ym transport. I hadn’t updated for months because I had a plan to move to a new server.

I would agree that the log is not that helpful but that is all that I could find! I searched through the log from the time before I had last restarted the gateway.

I think your suggestion re the S2S is probably correct - certainly better than any thoughts I had.

I would like to solve this problem so I am happy to try some things out. I am currently running with ym permanently open and a test user on line. I have enable the debug log. I don’t know if there will be other messages that your plugin will write to the debug log but I thought it was worth a try.

BTW I also coudln’t connect to ym the other day with the real client. I could connect with your plugin though!

BR

David

Hahahaha, my plugin did a better job of connecting than Yahoo itself?! I think that just made my day. =D

BTW I wasn’t implying that you were not giving me enough logs. Just that I should have made the plugin print out more. Do you have debug logs turned on? That looks like something that would have shown up in error logs.

Yes your plugin really did connect when ym failed. I had just created a new user that I wanted to use for the plugin. When I tried to login with the new user it failed repeatedly. I then tried the old login (after stopping the gateway) and it couldn’t connect either. I tried many times over a period of about 3 hours. Throughout that time I could connect with the plugin (1.1.0).

I have switched the debug long on as I indicated. The log I posted was from the error log not the debug log.

I will post what I find.

BR

David

OK - I have a bit more information but not that much! I left the debug log enabled but unfortunately it doesn’t seem to have picked up much information about this problem. However, it does seems that the transport is more inclined to fail if a ym user is left online. I have not tested this exhaustively, it is just an observation! I was away yesterday and so I had disconnected the user I was using for testing the previous night. The transport was still working correctly when I logged in again yesterday night. I left the test user logged in overnight and the transport had failed by the morning.

I have included the logs below but there doesn’t seem to be any information about the failure. Perhaps you will see something that I have missed.

BR

David

Error Log**********************

*******Transport was working at this point

2007.08.15 22:02:45 [org.jivesoftware.openfire.event.SessionEventDispatcher.dispatchEvent(SessionEv entDispatcher.java:83)

]

java.lang.NullPointerException

at org.jivesoftware.openfire.gateway.session.TransportSessionManager.removeSession (TransportSessionManager.java:166)

at org.jivesoftware.openfire.gateway.BaseTransport.sessionDestroyed(BaseTransport. java:2066)

at org.jivesoftware.openfire.event.SessionEventDispatcher.dispatchEvent(SessionEve ntDispatcher.java:66)

at org.jivesoftware.openfire.SessionManager.removeSession(SessionManager.java:1520 )

at org.jivesoftware.openfire.SessionManager$ClientSessionListener.onConnectionClos e(SessionManager.java:1596)

at org.jivesoftware.openfire.nio.NIOConnection.notifyCloseListeners(NIOConnection. java:169)

at org.jivesoftware.openfire.nio.NIOConnection.close(NIOConnection.java:152)

at org.jivesoftware.openfire.nio.ConnectionHandler.sessionClosed(ConnectionHandler .java:86)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.sessionClosed(A bstractIoFilterChain.java:677)

at org.apache.mina.common.support.AbstractIoFilterChain.callNextSessionClosed(Abst ractIoFilterChain.java:321)

at org.apache.mina.common.support.AbstractIoFilterChain.access$800(AbstractIoFilte rChain.java:54)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.sessionClosed( AbstractIoFilterChain.java:781)

at org.apache.mina.filter.codec.ProtocolCodecFilter.sessionClosed(ProtocolCodecFil ter.java:299)

at org.apache.mina.common.support.AbstractIoFilterChain.callNextSessionClosed(Abst ractIoFilterChain.java:321)

at org.apache.mina.common.support.AbstractIoFilterChain.access$800(AbstractIoFilte rChain.java:54)

at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.sessionClosed( AbstractIoFilterChain.java:781)

at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :286)

at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.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)

  • This is me checking to see if it is working - it isn’t!

2007.08.16 07:40:19 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send typing notification to yahoo user.

2007.08.16 07:40:19 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send typing notification to yahoo user.

2007.08.16 07:40:20 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Error occured while processing packet:

java.lang.IllegalStateException: Not logged in

at org.openymsg.network.Session.checkStatus(Unknown Source)

at org.openymsg.network.Session.sendMessage(Unknown Source)

at org.openymsg.network.Session.sendMessage(Unknown Source)

at org.jivesoftware.openfire.gateway.protocols.yahoo.YahooSession.sendMessage(Yaho oSession.java:353)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:228)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:176)

at org.jivesoftware.openfire.component.InternalComponentManager$RoutableComponent. process(InternalComponentManager.java:490)

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

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

at org.jivesoftware.openfire.net.StanzaHandler.processMessage(StanzaHandler.java:3 23)

at org.jivesoftware.openfire.net.ClientStanzaHandler.processMessage(ClientStanzaHa ndler.java:91)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:186)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)

at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)

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

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

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

at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)

at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)

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

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

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

at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)

at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.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)

2007.08.16 07:56:00 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Unable to set Yahoo Status:

java.net.SocketException: Software caused connection abort: socket write error

at java.net.SocketOutputStream.socketWrite0(Native Method)

at java.net.SocketOutputStream.socketWrite(Unknown Source)

at java.net.SocketOutputStream.write(Unknown Source)

at java.io.BufferedOutputStream.flushBuffer(Unknown Source)

at java.io.BufferedOutputStream.flush(Unknown Source)

at java.io.DataOutputStream.flush(Unknown Source)

at org.openymsg.network.DirectConnectionHandler.sendPacket(Unknown Source)

at org.openymsg.network.Session.sendPacket(Unknown Source)

at org.openymsg.network.Session.sendPacket(Unknown Source)

at org.openymsg.network.Session.transmitNewStatus(Unknown Source)

at org.openymsg.network.Session.setStatus(Unknown Source)

at org.jivesoftware.openfire.gateway.protocols.yahoo.YahooSession.updateStatus(Yah ooSession.java:384)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:325)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:173)

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(Presenc eUpdateHandler.java:258)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:100)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:88)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.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.net.StanzaHandler.processPresence(StanzaHandler.java: 306)

at org.jivesoftware.openfire.net.ClientStanzaHandler.processPresence(ClientStanzaH andler.java:85)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:231)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)

at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)

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

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

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

at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)

at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)

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

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

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

at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)

at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.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)

2007.08.16 08:21:01 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Unable to set Yahoo Status:

java.net.SocketException: Software caused connection abort: socket write error

at java.net.SocketOutputStream.socketWrite0(Native Method)

at java.net.SocketOutputStream.socketWrite(Unknown Source)

at java.net.SocketOutputStream.write(Unknown Source)

at java.io.BufferedOutputStream.flushBuffer(Unknown Source)

at java.io.BufferedOutputStream.flush(Unknown Source)

at java.io.DataOutputStream.flush(Unknown Source)

at org.openymsg.network.DirectConnectionHandler.sendPacket(Unknown Source)

at org.openymsg.network.Session.sendPacket(Unknown Source)

at org.openymsg.network.Session.sendPacket(Unknown Source)

at org.openymsg.network.Session.transmitNewStatus(Unknown Source)

at org.openymsg.network.Session.setStatus(Unknown Source)

at org.jivesoftware.openfire.gateway.protocols.yahoo.YahooSession.updateStatus(Yah ooSession.java:384)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:325)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:173)

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(Presenc eUpdateHandler.java:258)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:100)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:88)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.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.net.StanzaHandler.processPresence(StanzaHandler.java: 306)

at org.jivesoftware.openfire.net.ClientStanzaHandler.processPresence(ClientStanzaH andler.java:85)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:231)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)

at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)

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

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

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

at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)

at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)

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

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

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

at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)

at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.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)

2007.08.16 08:52:58 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Unable to set Yahoo Status:

java.net.SocketException: Software caused connection abort: socket write error

at java.net.SocketOutputStream.socketWrite0(Native Method)

at java.net.SocketOutputStream.socketWrite(Unknown Source)

at java.net.SocketOutputStream.write(Unknown Source)

at java.io.BufferedOutputStream.flushBuffer(Unknown Source)

at java.io.BufferedOutputStream.flush(Unknown Source)

at java.io.DataOutputStream.flush(Unknown Source)

at org.openymsg.network.DirectConnectionHandler.sendPacket(Unknown Source)

at org.openymsg.network.Session.sendPacket(Unknown Source)

at org.openymsg.network.Session.sendPacket(Unknown Source)

at org.openymsg.network.Session.transmitNewStatus(Unknown Source)

at org.openymsg.network.Session.setStatus(Unknown Source)

at org.jivesoftware.openfire.gateway.protocols.yahoo.YahooSession.updateStatus(Yah ooSession.java:384)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:325)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:173)

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(Presenc eUpdateHandler.java:258)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:100)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.java:88)

at org.jivesoftware.openfire.handler.PresenceUpdateHandler.process(PresenceUpdateH andler.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.net.StanzaHandler.processPresence(StanzaHandler.java: 306)

at org.jivesoftware.openfire.net.ClientStanzaHandler.processPresence(ClientStanzaH andler.java:85)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:231)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)

at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)

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

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

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

at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)

at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)

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

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

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

at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)

at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.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)

2007.08.16 08:58:55 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send typing notification to yahoo user.

2007.08.16 08:58:55 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Failed to send typing notification to yahoo user.

2007.08.16 08:58:58 [org.jivesoftware.openfire.gateway.util.Log4JToOpenfireAppender.append(Log4JToO penfireAppender.java:49)

] Error occured while processing packet:

java.lang.IllegalStateException: Not logged in

at org.openymsg.network.Session.checkStatus(Unknown Source)

at org.openymsg.network.Session.sendMessage(Unknown Source)

at org.openymsg.network.Session.sendMessage(Unknown Source)

at org.jivesoftware.openfire.gateway.protocols.yahoo.YahooSession.sendMessage(Yaho oSession.java:353)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:228)

at org.jivesoftware.openfire.gateway.BaseTransport.processPacket(BaseTransport.jav a:176)

at org.jivesoftware.openfire.component.InternalComponentManager$RoutableComponent. process(InternalComponentManager.java:490)

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

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

at org.jivesoftware.openfire.net.StanzaHandler.processMessage(StanzaHandler.java:3 23)

at org.jivesoftware.openfire.net.ClientStanzaHandler.processMessage(ClientStanzaHa ndler.java:91)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:186)

at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:153)

at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandl er.java:132)

at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived (AbstractIoFilterChain.java:703)

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

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

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

at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimplePr otocolDecoderOutput.java:62)

at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecF ilter.java:200)

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

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

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

at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java :266)

at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(Execut orFilter.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)

  • Debug Log *********************************

2007.08.15 23:58:20 Received presence packet:

2007.08.15 23:58:20 An existing resource has changed status: david@rectoryhouse.net/Pandion

2007.08.15 23:58:20 Updating status for TransportSession[david@rectoryhouse.net]

2007.08.15 23:58:20 yahoo: Sending packet:

2007.08.16 00:09:35 Finishing Outgoing Server Reader. Closing session: org.jivesoftware.openfire.session.OutgoingServerSession@4cdac8 status: -1 address: googlemail.com id: F2E9F727927051AC

java.net.SocketException: socket closed

at java.net.SocketInputStream.socketRead0(Native Method)

at java.net.SocketInputStream.read(Unknown Source)

at org.jivesoftware.openfire.net.ServerTrafficCounter$InputStreamWrapper.read(Serv erTrafficCounter.java:201)

at sun.nio.cs.StreamDecoder.readBytes(Unknown Source)

at sun.nio.cs.StreamDecoder.implRead(Unknown Source)

at sun.nio.cs.StreamDecoder.read(Unknown Source)

at java.io.InputStreamReader.read(Unknown Source)

at org.xmlpull.mxp1.MXParser.fillBuf(MXParser.java:2992)

at org.xmlpull.mxp1.MXParser.more(MXParser.java:3046)

at org.jivesoftware.openfire.net.MXParser.nextImpl(MXParser.java:320)

at org.xmlpull.mxp1.MXParser.nextToken(MXParser.java:1100)

at org.dom4j.io.XMPPPacketReader.parseDocument(XMPPPacketReader.java:317)

at org.jivesoftware.openfire.server.OutgoingServerSocketReader$1.run(OutgoingServe rSocketReader.java:92)

2007.08.16 00:22:20 Magic:YMSG Version:0 Length:44 Service:Y6_STATUS_UPDATE Status:1 SessionId:0xffffffffcb8bb551

2007.08.16 00:22:20 Updating status for

2007.08.16 00:22:20 yahoo: Sending packet:

2007.08.16 00:23:20 An existing resource has changed status: david@rectoryhouse.net/Pandion

2007.08.16 00:23:20 Updating status for TransportSession[david@rectoryhouse.net]

2007.08.16 00:23:20 yahoo: Sending packet:

  • some s2s activity

2007.08.16 02:19:42 Magic:YMSG Version:0 Length:17 Service:AUTHRESP Status:-1 SessionId:0xffffffffcb8bb551

2007.08.16 07:38:38 yahoo: rosterLoaded david

2007.08.16 07:38:38 Received presence packet:

2007.08.16 07:38:38 An existing resource has changed status: david@rectoryhouse.net/Pandion

2007.08.16 07:38:38 Updating status for TransportSession[david@rectoryhouse.net]

2007.08.16 07:38:38 yahoo: Sending packet:

  • more s2s

2007.08.16 07:40:19 Received message packet:

2007.08.16 07:44:41 Ignoring extra content {}

  • more s2s

  • then these messages start

2007.08.16 07:50:48 Exec[0]: ConnectionTester.pingSession()

2007.08.16 07:50:48 --Object created, not stored. Call params () id=2613_1187247039306. Using (XHR,POST)

2007.08.16 07:50:48 Returning: id[2613_1187247039306] assign[s0] xhr[true]

2007.08.16 07:50:48 var s0=null;

DWREngine._handleResponse(‘2613_1187247039306’, s0);

2007.08.16 07:51:47 Exec[0]: ConnectionTester.pingSession()

2007.08.16 07:51:47 --Object created, not stored. Call params () id=3774_1187247099322. Using (XHR,POST)

2007.08.16 07:51:47 Returning: id[3774_1187247099322] assign[s0] xhr[true]

2007.08.16 07:51:47 var s0=null;

DWREngine._handleResponse(‘3774_1187247099322’, s0);

2007.08.16 07:52:47 Exec[0]: ConnectionTester.pingSession()

2007.08.16 07:52:47 --Object created, not stored. Call params () id=651_1187247159338. Using (XHR,POST)

2007.08.16 07:52:47 Returning: id[651_1187247159338] assign[s0] xhr[true]

2007.08.16 07:52:47 var s0=null;

DWREngine._handleResponse(‘651_1187247159338’, s0);

2007.08.16 07:53:47 Exec[0]: ConnectionTester.pingSession()

2007.08.16 07:53:47 --Object created, not stored. Call params () id=9688_1187247219338. Using (XHR,POST)

2007.08.16 07:53:47 Returning: id[9688_1187247219338] assign[s0] xhr[true]

2007.08.16 07:53:47 var s0=null;

DWREngine._handleResponse(‘9688_1187247219338’, s0);

2007.08.16 07:54:47 Exec[0]: ConnectionTester.pingSession()

2007.08.16 07:54:47 --Object created, not stored. Call params () id=3338_1187247279338. Using (XHR,POST)

2007.08.16 07:54:47 Returning: id[3338_1187247279338] assign[s0] xhr[true]

2007.08.16 07:54:47 var s0=null;

DWREngine._handleResponse(‘3338_1187247279338’, s0);

2007.08.16 07:55:47 Exec[0]: ConnectionTester.pingSession()

2007.08.16 07:55:47 --Object created, not stored. Call params () id=572_1187247339353. Using (XHR,POST)

2007.08.16 07:55:47 Returning: id[572_1187247339353] assign[s0] xhr[true]

2007.08.16 07:55:47 var s0=null;

DWREngine._handleResponse(‘572_1187247339353’, s0);

  • more s2s

2007.08.16 07:56:00 Received presence packet:

  • more s2s and ConnectionTester

2007.08.16 08:21:01 Received presence packet:

  • more s2s and more of the same ConnectionTester messages

2007.08.16 08:58:49 Exec[0]: ConnectionTester.pingSession()

2007.08.16 08:58:49 --Object created, not stored. Call params () id=2332_1187251119978. Using (XHR,POST)

2007.08.16 08:58:49 Returning: id[2332_1187251119978] assign[s0] xhr[true]

2007.08.16 08:58:49 var s0=null;

DWREngine._handleResponse(‘2332_1187251119978’, s0);

2007.08.16 08:58:55 Received message packet:

2007.08.16 08:59:49 Exec[0]: ConnectionTester.pingSession()

2007.08.16 08:59:49 --Object created, not stored. Call params () id=1696_1187251179994. Using (XHR,POST)

2007.08.16 08:59:49 Returning: id[1696_1187251179994] assign[s0] xhr[true]

2007.08.16 08:59:49 var s0=null;

DWREngine._handleResponse(‘1696_1187251179994’, s0);

2007.08.16 09:00:49 Exec[0]: ConnectionTester.pingSession()

2007.08.16 09:00:49 --Object created, not stored. Call params () id=8670_1187251240010. Using (XHR,POST)

2007.08.16 09:00:49 Returning: id[8670_1187251240010] assign[s0] xhr[true]

2007.08.16 09:00:49 var s0=null;

DWREngine._handleResponse(‘8670_1187251240010’, s0);

2007.08.16 09:01:49 Exec[0]: ConnectionTester.pingSession()

2007.08.16 09:01:49 --Object created, not stored. Call params () id=9357_1187251300025. Using (XHR,POST)

2007.08.16 09:01:49 Returning: id[9357_1187251300025] assign[s0] xhr[true]

2007.08.16 09:01:49 var s0=null;

DWREngine._handleResponse(‘9357_1187251300025’, s0);

  • Sending a test message just before restarting transport

  • The message is not received because the transport has failed

2007.08.16 09:32:40 Received message packet:

2007.08.16 09:34:16 Component registered for domain: yahoo

2007.08.16 09:34:16 Returning: id[7659_1187253246681] assign[s0] xhr[true]

2007.08.16 09:34:16 var s0=true;

DWREngine._handleResponse(‘7659_1187253246681’, s0);

2007.08.16 09:34:16 Magic:YMSG Version:0 Length:105 Service:AUTH Status:1 SessionId:0xfffffffffe90e4be w

2007.08.16 09:34:17 Magic:YMSG Version:0 Length:684 Service:LIST Status:0 SessionId:0xfffffffffe90e4be [Transport Buddies:nlibertys,rectorydp

] [] [] [] [] [] [] http://JwttXwed2EZvKiEkU0T5.Q–

2007.08.16 09:34:17 add new group from list YahooGroup

2007.08.16 09:34:17 Updating status for

2007.08.16 09:34:17 (YAHOO) Storing new buddy:

2007.08.16 09:34:17 Updating status for

2007.08.16 09:34:17 (YAHOO) Storing new buddy:

2007.08.16 09:34:17 Syncing Legacy Roster: [, ]

2007.08.16 09:34:17 ROSTERSYNC: We have new, adding rectorydp

**********************etc…

  • transport now working

It just failed again!

I found in the following information in the log. It mainly seems to relate to a test I had done where I logged out my test ym user, sent some messages to the test ym user and then logged in again. The messages were stored and forwarded but then there seem to be some errors. I don’t know if the transport failed at this point or later but there are no more messages in the debug log.

BR

David

2007.08.16 10:16:58 Magic:YMSG Version:0 Length:118 Service:LOGON Status:1 SessionId:0xfffffffffe90e4be

2007.08.16 10:16:58 Updating status for

2007.08.16 10:16:58 yahoo: Sending packet:

2007.08.16 10:17:20 No such ServiceType value ‘235’ (which is ‘eb’ in hex).

2007.08.16 10:17:20 Magic:YMSG Version:0 Length:128 Service:null Status:1 SessionId:0xfffffffffe90e4be http://1.1.0

2007.08.16 10:17:20 unknow packet: Magic:YMSG Version:0 Length:128 Service:null Status:1 SessionId:0xfffffffffe90e4be http://1.1.0

2007.08.16 10:17:23 No such ServiceType value ‘235’ (which is ‘eb’ in hex).

2007.08.16 10:17:23 Magic:YMSG Version:0 Length:125 Service:null Status:1 SessionId:0xfffffffffe90e4be http://1.0.5

2007.08.16 10:17:23 unknow packet: Magic:YMSG Version:0 Length:125 Service:null Status:1 SessionId:0xfffffffffe90e4be http://1.0.5

Just curious, is your test account user able to see or add other yahoo friends through the gateway? I’m seeing some similar error messages.

Hi ubuild00, my test accounts (and my real account) are able to see other yahoo friends just fine. =/

Also, both of you, the devs of openymsg found a big bug regarding the session pinger that is fixed in trunk at this time and will be fixed in 1.1.1. I suspect that’s what was causing this issue!

I’m sorry, I should have said “add” new users. Presence is not an issue. Yahoo gateway users are able to see existing friends, but not send or receive new friend requests. I start seeing the same messages as the first post in the thread. The add to roster requests are seen in the debug log, but are not acted upon.

I’ll wait for the new release and perhaps start a new thread if the update fixes rectorydp’s issue but not mine.

Thanks again!

Hello ubulid00

I haven’t been able to add users through the gateway. I saw some pretty odd behaivior when I tried to to that. The user appeared to be added but authorization never took place. The user would disappear when I signed out and back in again. There were a few other oddities that I cannot remember at the moment. I just went to the ym client to add the users. I don’t have lots of users wanting to add ym users thorugh the gateway so it has not been a problem for me but I believe there is an issue.

It seems my problem with the transport failing is getting worse. I had to restart it about 6 times yesterday. It has already failed twice today. I hope that the bug that has been identified will fix the problem as the transport now requires too much attention!

Thanks again to Daniel for all the work on the gateway.

Hello

The new release (1.1.1) does appear to have fixed the problem with the transport failing. It has only been running since yesterrday morning so I will continue monitoring. However, on the last day before I upgraded (Sunday) the transport was failing every few hours. It actually seemed to be getting worse!

So many thanks jadestorm for the speedy release. I am very happy at the moment

Excellent, thanks for letting me know!!!

The Gateway has been running for 3 days now and the Yahoo transport has been rock solid! Thanks again jadestorm.

I’m having the same problem. Openfire Enterprise 3.3.3, spark 2.5.7 IMGW 1.1.3a