PEPService fails to be added to a clustered Cache
Description
Environment
None
Activity
Show:

Daryl Herzmann January 4, 2013 at 1:41 PM
Thanks, dogfooded just now and did not get any errors. Will mark as fixed

Tom Evans January 4, 2013 at 9:06 AM
Ready for dogfooding ... if you dare!

Tom Evans January 4, 2013 at 9:04 AM
Yikes! Hope there's no "3-stikes" rule in effect ... apologies for the churn. How quickly race conditions turn into steeplechases.
Anyway - It seems we were switching to the clustered factory strategy class prematurely (after initiating the cluster start, but before the server had actually joined the cluster). I have applied another small change to the CacheFactory (SVN 13383) to correct this timing problem.

Daryl Herzmann January 3, 2013 at 6:06 PM
Didn't appear to work and another bug appeared
2013.01.03 12:04:22 org.jivesoftware.openfire.handler.IQHandler - Internal server error
java.lang.ClassCastException: org.jivesoftware.util.cache.DefaultCache cannot be cast to com.jivesoftware.util.cache.ClusteredCache
at com.jivesoftware.util.cache.ClusteredCacheFactory.getLock(ClusteredCacheFactory.java:370)
at org.jivesoftware.util.cache.CacheFactory.getLock(CacheFactory.java:417)
at org.jivesoftware.openfire.spi.RoutingTableImpl.addClientRoute(RoutingTableImpl.java:173)
at org.jivesoftware.openfire.SessionManager.addSession(SessionManager.java:554)
at org.jivesoftware.openfire.session.LocalClientSession.setAuthToken(LocalClientSession.java:600)
at org.jivesoftware.openfire.handler.IQBindHandler.handleIQ(IQBindHandler.java:154)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:65)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:372)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:121)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:76)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:337)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler.java:93)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:302)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:194)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:181)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:58)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:185)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:239)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:283)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:662)
2013.01.03 12:04:23 org.jivesoftware.openfire.handler.IQHandler - Internal server error
java.lang.ClassCastException: org.jivesoftware.util.cache.DefaultCache cannot be cast to com.jivesoftware.util.cache.ClusteredCache
at com.jivesoftware.util.cache.ClusteredCacheFactory.getLock(ClusteredCacheFactory.java:370)
at org.jivesoftware.util.cache.CacheFactory.getLock(CacheFactory.java:417)
at org.jivesoftware.openfire.spi.RoutingTableImpl.addClientRoute(RoutingTableImpl.java:173)
at org.jivesoftware.openfire.SessionManager.addSession(SessionManager.java:554)
at org.jivesoftware.openfire.session.LocalClientSession.setAuthToken(LocalClientSession.java:600)
at org.jivesoftware.openfire.handler.IQBindHandler.handleIQ(IQBindHandler.java:154)
at org.jivesoftware.openfire.handler.IQHandler.process(IQHandler.java:65)
at org.jivesoftware.openfire.IQRouter.handle(IQRouter.java:372)
at org.jivesoftware.openfire.IQRouter.route(IQRouter.java:121)
at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:76)
at org.jivesoftware.openfire.net.StanzaHandler.processIQ(StanzaHandler.java:337)
at org.jivesoftware.openfire.net.ClientStanzaHandler.processIQ(ClientStanzaHandler.java:93)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:302)
at org.jivesoftware.openfire.net.StanzaHandler.process(StanzaHandler.java:194)
at org.jivesoftware.openfire.nio.ConnectionHandler.messageReceived(ConnectionHandler.java:181)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.codec.support.SimpleProtocolDecoderOutput.flush(SimpleProtocolDecoderOutput.java:58)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:185)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.filter.executor.ExecutorFilter.processEvent(ExecutorFilter.java:239)
at org.apache.mina.filter.executor.ExecutorFilter$ProcessEventsRunnable.run(ExecutorFilter.java:283)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
at java.lang.Thread.run(Thread.java:662)
2013.01.03 12:04:28 org.jivesoftware.openfire.cluster.ClusterManager -
java.lang.NullPointerException
at org.jivesoftware.openfire.muc.cluster.OccupantAddedEvent.getNickname(OccupantAddedEvent.java:72)
at org.jivesoftware.openfire.muc.spi.LocalMUCRoom.occupantAdded(LocalMUCRoom.java:731)
at org.jivesoftware.openfire.muc.cluster.OccupantAddedEvent$1.run(OccupantAddedEvent.java:129)
at org.jivesoftware.openfire.muc.cluster.MUCRoomTask.execute(MUCRoomTask.java:85)
at org.jivesoftware.openfire.muc.cluster.OccupantAddedEvent.run(OccupantAddedEvent.java:127)
at org.jivesoftware.openfire.muc.MultiUserChatManager.joinedCluster(MultiUserChatManager.java:788)
at org.jivesoftware.openfire.cluster.ClusterManager$1.run(ClusterManager.java:69)

Tom Evans January 3, 2013 at 5:52 PM
Looks like a timing issue during cluster startup. I have added some synchronization to the CacheFactory that should fix this (SVN 13382).
Fixed
Details
Details
Details
Created November 14, 2012 at 8:31 PM
Updated January 4, 2013 at 1:41 PM
Resolved January 4, 2013 at 1:41 PM
After adding Hazelcast to the XMPP domain at igniterealtime.org, I noticed stack traces like these in the error log:
2012.11.14 13:52:03 org.jivesoftware.openfire.PresenceRouter - Could not route packet com.hazelcast.nio.HazelcastSerializationException: java.io.NotSerializableException: org.jivesoftware.openfire.commands.AdHocCommandManager at com.hazelcast.nio.AbstractSerializer.toByte(AbstractSerializer.java:111) at com.hazelcast.nio.AbstractSerializer.toByteArray(AbstractSerializer.java:139) at com.hazelcast.nio.Serializer.writeObject(Serializer.java:52) at com.hazelcast.impl.ThreadContext.toData(ThreadContext.java:131) at com.hazelcast.nio.IOUtil.toData(IOUtil.java:136) at com.hazelcast.impl.BaseManager$RequestBasedCall.setLocal(BaseManager.java:522) at com.hazelcast.impl.BaseManager$ResponseQueueCall.setLocal(BaseManager.java:555) at com.hazelcast.impl.ConcurrentMapManager$MPut.txnalPut(ConcurrentMapManager.java:1844) at com.hazelcast.impl.ConcurrentMapManager$MPut.txnalPut(ConcurrentMapManager.java:1799) at com.hazelcast.impl.ConcurrentMapManager$MPut.put(ConcurrentMapManager.java:1664) at com.hazelcast.impl.MProxyImpl$MProxyReal.put(MProxyImpl.java:632) at com.hazelcast.impl.MProxyImpl$MProxyReal.put(MProxyImpl.java:606) at com.hazelcast.impl.MProxyImpl.put(MProxyImpl.java:173) at com.hazelcast.impl.MProxyImpl.put(MProxyImpl.java:124) at com.jivesoftware.util.cache.ClusteredCache.put(ClusteredCache.java:81) at org.jivesoftware.util.cache.CacheWrapper.put(CacheWrapper.java:129) at org.jivesoftware.openfire.pep.PEPServiceManager.loadPEPServiceFromDB(PEPServiceManager.java:148) at org.jivesoftware.openfire.pep.PEPServiceManager.getPEPService(PEPServiceManager.java:78) at org.jivesoftware.openfire.pep.IQPEPHandler.remoteUserAvailable(IQPEPHandler.java:637) at org.jivesoftware.openfire.user.RemotePresenceEventDispatcher.remoteUserAvailable(RemotePresenceEventDispatcher.java:75) at org.jivesoftware.openfire.PresenceRouter.handle(PresenceRouter.java:158) at org.jivesoftware.openfire.PresenceRouter.route(PresenceRouter.java:85) at org.jivesoftware.openfire.spi.PacketRouterImpl.route(PacketRouterImpl.java:84) at org.jivesoftware.openfire.net.SocketReader.processPresence(SocketReader.java:284) at org.jivesoftware.openfire.net.ServerSocketReader.access$201(ServerSocketReader.java:60) at org.jivesoftware.openfire.net.ServerSocketReader$2.run(ServerSocketReader.java:122) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619) Caused by: java.io.NotSerializableException: org.jivesoftware.openfire.commands.AdHocCommandManager at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1156) at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1509) at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1474) at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1392) at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1150) at java.io.ObjectOutputStream.writeUnshared(ObjectOutputStream.java:393) at com.hazelcast.nio.DefaultSerializer$ObjectSerializer.writeNormal(DefaultSerializer.java:433) at com.hazelcast.nio.DefaultSerializer$ObjectSerializer.write(DefaultSerializer.java:387) at com.hazelcast.nio.DefaultSerializer.write(DefaultSerializer.java:128) at com.hazelcast.nio.CustomSerializerAdapter.write(CustomSerializerAdapter.java:28) at com.hazelcast.nio.AbstractSerializer.toByte(AbstractSerializer.java:103) ... 28 more
The root cause lies in
org.jivesoftware.openfire.pep.PEPServiceManager#pepServices
, which is a cache of PEPService instances. When used in a cluster, it tries to serialize PEPService instances, which fails. The AdHocCommandManager that is part of the instance (org.jivesoftware.openfire.pep.PEPService#adHocCommandManager
) is not Serializable.The obvious way out would be making that class Serializable. I do wonder if that's not adding to much to an already rather bloated cached entity.