7 Replies Latest reply on Feb 16, 2006 10:48 AM by Bela Ban

    Listener ignored => ChannelException: unable to setup the pr

    Sven Schauwvliege Newbie

      When trying to enable clustered caching we ran into this problem:
      Setup:
      We have 2 servers on one of the servers (server2) we receve no errors

      configuration on server 1 ip: 192.168.100.51

      #cache.memory=true
      #cache.capacity=100
      #gdp.cache.debug=false
      gdp.cache.lifetime=1800
      #cache.cluster.multicast.ip=231.12.21.100
      cache.cluster.properties=UDP(mcast_addr=231.12.21.100;mcast_port=30210;bind_addr=192.168.100.51:1509;ip_ttl=32;\
      mcast_send_buf_size=150000;mcast_recv_buf_size=80000):\
      PING(timeout=2000;num_initial_members=10):\
      MERGE2(min_interval=5000;max_interval=10000):\
      FD_SOCK:VERIFY_SUSPECT(timeout=2000):\
      pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):\
      UNICAST(timeout=300,600,1200,2400):\
      pbcast.STABLE(desired_avg_gossip=20000):\
      FRAG(frag_size=8096;down_thread=false;up_thread=false):\
      pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true)
      


      configuration on server2 ip: 192.168.100.45
      #cache.memory=true
      #cache.capacity=100
      #gdp.cache.debug=false
      gdp.cache.lifetime=1800
      #cache.cluster.multicast.ip=231.12.21.100
      cache.cluster.properties=UDP(mcast_addr=231.12.21.100;mcast_port=30210;bind_addr=192.168.100.45;ip_ttl=32;\
      mcast_send_buf_size=150000;mcast_recv_buf_size=80000):\
      PING(timeout=2000;num_initial_members=10):\
      MERGE2(min_interval=5000;max_interval=10000):\
      FD_SOCK:VERIFY_SUSPECT(timeout=2000):\
      pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):\
      UNICAST(timeout=300,600,1200,2400):\
      pbcast.STABLE(desired_avg_gossip=20000):\
      FRAG(frag_size=8096;down_thread=false;up_thread=false):\
      pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true)
      


      oscache.properties (on both servers)
      cache.memory=true
      cache.capacity=2000
      cache.algorithm=com.opensymphony.oscache.base.algorithm.LRUCache
      gdp.cache.debug=false
      gdp.cache.lifetime=3600
      #for development purposes
      #gdp.cache.lifetime=60
      cache.event.listeners=com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener
      


      Error:
      2006-02-15 18:01:31,109 [AloneScheduler_Worker-0] ERROR com.opensymphony.oscache.base.AbstractCacheAdministrator (AbstractCacheAdministrator.java:332) - Could not initialize listener 'com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener'. Listener ignored. - configureStandardListeners
      com.opensymphony.oscache.base.InitializationException: Initialization failed: ChannelException: unable to setup the protocol stack
       at com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener.initialize(JavaGroupsBroadcastingListener.java:119)
       at com.opensymphony.oscache.base.AbstractCacheAdministrator.configureStandardListeners(AbstractCacheAdministrator.java:330)
       at com.opensymphony.oscache.general.GeneralCacheAdministrator.createCache(GeneralCacheAdministrator.java:297)
       at com.opensymphony.oscache.general.GeneralCacheAdministrator.<init>(GeneralCacheAdministrator.java:99)
       at com.gdp3000.permission.PermissionDataManager.getCacheAdmin(Unknown Source)
       at com.gdp3000.permission.PermissionDataManager.getUserWithFilter(Unknown Source)
       at com.gdp3000.permission.PermissionDataManager.getUserByUid(Unknown Source)
       at com.gdp3000.permission.PermissionManager.checkUserIdPassword(Unknown Source)
       at com.gdp3000.permission.PermissionManager.authenticate(Unknown Source)
       at com.gudrun.scheduler.GdpStatefulJob.execute(Unknown Source)
       at com.gdp3000.communication.email.EMailListener.execute(Unknown Source)
       at org.quartz.core.JobRunShell.run(JobRunShell.java:188)
       at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:511)
      2006-02-15 18:01:31,156 [AloneScheduler_Worker-2] ERROR com.opensymphony.oscache.base.AbstractCacheAdministrator (AbstractCacheAdministrator.java:332) - Could not initialize listener 'com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener'. Listener ignored. - configureStandardListeners
      com.opensymphony.oscache.base.InitializationException: Initialization failed: ChannelException: unable to setup the protocol stack
       at com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener.initialize(JavaGroupsBroadcastingListener.java:119)
       at com.opensymphony.oscache.base.AbstractCacheAdministrator.configureStandardListeners(AbstractCacheAdministrator.java:330)
       at com.opensymphony.oscache.general.GeneralCacheAdministrator.createCache(GeneralCacheAdministrator.java:297)
       at com.opensymphony.oscache.general.GeneralCacheAdministrator.<init>(GeneralCacheAdministrator.java:99)
       at com.gdp3000.permission.PermissionDataManager.getCacheAdmin(Unknown Source)
       at com.gdp3000.permission.PermissionDataManager.getUserWithFilter(Unknown Source)
       at com.gdp3000.permission.PermissionDataManager.getUserByUid(Unknown Source)
       at com.gdp3000.permission.PermissionManager.checkUserIdPassword(Unknown Source)
       at com.gdp3000.permission.PermissionManager.authenticate(Unknown Source)
       at com.gudrun.scheduler.GdpStatefulJob.execute(Unknown Source)
       at com.gdp3000.communication.email.EMailListener.execute(Unknown Source)
       at org.quartz.core.JobRunShell.run(JobRunShell.java:188)
       at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:511)
      


      What are we missing here ?

        • 1. Re: Listener ignored => ChannelException: unable to setup th
          Bela Ban Master

          You should add a TRACE or DEBUG category for org.jgroups to see what caused the channel to not start.

          • 2. Re: Listener ignored => ChannelException: unable to setup th
            Sven Schauwvliege Newbie

            Hi, thanks for the help

            this is what comes from the log files:

            2006-02-16 09:46:02,875 [AloneScheduler_Worker-2] DEBUG org.jgroups.conf.ClassConfigurator (ClassConfigurator.java:84) - mapping is:
            1: class org.jgroups.stack.IpAddress
            2: class org.jgroups.protocols.CAUSAL$CausalHeader
            3: class org.jgroups.protocols.FD$FdHeader
            4: class org.jgroups.protocols.FD_PID$FdHeader
            5: class org.jgroups.protocols.FD_PROB$FdHeader
            6: class org.jgroups.protocols.FD_SOCK$FdHeader
            7: class org.jgroups.protocols.FRAG$FragHeader
            8: class org.jgroups.protocols.MERGE$MergeHeader
            9: class org.jgroups.protocols.NakAckHeader
            10: class org.jgroups.protocols.PARTITIONER$PartitionerHeader
            11: class org.jgroups.protocols.PerfHeader
            12: class org.jgroups.protocols.PIGGYBACK$PiggybackHeader
            13: class org.jgroups.protocols.PingHeader
            14: class org.jgroups.protocols.TcpHeader
            15: class org.jgroups.protocols.TOTAL$Header
            16: class org.jgroups.protocols.TOTAL_OLD$TotalHeader
            17: class org.jgroups.protocols.TOTAL_TOKEN$TotalTokenHeader
            18: class org.jgroups.protocols.TOTAL_TOKEN$RingTokenHeader
            19: class org.jgroups.protocols.TunnelHeader
            20: class org.jgroups.protocols.UdpHeader
            21: class org.jgroups.protocols.UNICAST$UnicastHeader
            22: class org.jgroups.protocols.VERIFY_SUSPECT$VerifyHeader
            23: class org.jgroups.protocols.WANPIPE$WanPipeHeader
            24: class org.jgroups.protocols.pbcast.GMS$GmsHeader
            25: class org.jgroups.protocols.pbcast.NakAckHeader
            26: class org.jgroups.protocols.pbcast.PbcastHeader
            27: class org.jgroups.protocols.pbcast.STABLE$StableHeader
            28: class org.jgroups.protocols.pbcast.STATE_TRANSFER$StateHeader
            29: class org.jgroups.protocols.SMACK$SmackHeader
            50: class org.jgroups.service.lease.LeaseRequestHeader
            51: class org.jgroups.service.lease.LeaseResponseHeader
            52: class org.jgroups.service.lease.DenyResponseHeader
            53: class org.jgroups.protocols.COMPRESS$CompressHeader
             - <init>
            2006-02-16 09:46:02,875 [AloneScheduler_Worker-3] ERROR com.opensymphony.oscache.base.AbstractCacheAdministrator (AbstractCacheAdministrator.java:332) - Could not initialize listener 'com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener'. Listener ignored. - configureStandardListeners
            com.opensymphony.oscache.base.InitializationException: Initialization failed: ChannelException: unable to setup the protocol stack
             at com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener.initialize(JavaGroupsBroadcastingListener.java:119)
             at com.opensymphony.oscache.base.AbstractCacheAdministrator.configureStandardListeners(AbstractCacheAdministrator.java:330)
             at com.opensymphony.oscache.general.GeneralCacheAdministrator.createCache(GeneralCacheAdministrator.java:297)
             at com.opensymphony.oscache.general.GeneralCacheAdministrator.<init>(GeneralCacheAdministrator.java:99)
             at com.gdp3000.permission.PermissionDataManager.getCacheAdmin(Unknown Source)
             at com.gdp3000.permission.PermissionDataManager.getUserWithFilter(Unknown Source)
             at com.gdp3000.permission.PermissionDataManager.getUserByUid(Unknown Source)
             at com.gdp3000.permission.PermissionManager.checkUserIdPassword(Unknown Source)
             at com.gdp3000.permission.PermissionManager.authenticate(Unknown Source)
             at com.gudrun.scheduler.GdpStatefulJob.execute(Unknown Source)
             at com.gdp3000.communication.email.EMailListener.execute(Unknown Source)
             at org.quartz.core.JobRunShell.run(JobRunShell.java:188)
             at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:511)


            • 3. Re: Listener ignored => ChannelException: unable to setup th
              Bela Ban Master

              OSCache might eat the exception at:
              com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener.initialize(JavaGr
              oupsBroadcastingListener.java:119)

              I suggest you debug this to get the exception. It should say exactly where the configuration is incorrect.

              • 4. Re: Listener ignored => ChannelException: unable to setup th
                Sven Schauwvliege Newbie

                I have managed to set the properties right (no more errors) but the clustered cache doesnt work

                here is a part of the log file:

                2006-02-16 15:00:38,046 [DownHandler (STABLE)] DEBUG org.jgroups.protocols.pbcast.STABLE (STABLE.java:322) - stable task started; num_gossip_runs=3, max_gossip_runs=3 - startStableTask
                2006-02-16 15:00:38,046 [DownHandler (STABLE)] DEBUG org.jgroups.protocols.pbcast.STABLE (STABLE.java:322) - stable task started; num_gossip_runs=3, max_gossip_runs=3 - startStableTask
                2006-02-16 15:00:38,046 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3853 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:38,046 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:117) - JavaGroups clustering support started successfully - initialize
                2006-02-16 15:00:38,046 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3853 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:38,046 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:251) - VIEW_CHANGE received: [newweb1-staging:3853] - down
                2006-02-16 15:00:38,046 [PullPushAdapterThread] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:184) - A new member at address 'newweb1-staging:3853' has joined the cluster - memberJoined
                2006-02-16 15:00:38,046 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:117) - JavaGroups clustering support started successfully - initialize
                2006-02-16 15:00:38,046 [MERGE2.FindSubgroups thread] DEBUG org.jgroups.protocols.MERGE2 (MERGE2.java:230) - merge task started - run
                2006-02-16 15:00:38,046 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:251) - VIEW_CHANGE received: [newweb1-staging:3853] - down
                2006-02-16 15:00:38,046 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3853 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:38,046 [PullPushAdapterThread] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:184) - A new member at address 'newweb1-staging:3853' has joined the cluster - memberJoined
                2006-02-16 15:00:38,046 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:490) - first member; cache is empty - getCacheFromCoordinator
                2006-02-16 15:00:38,046 [MERGE2.FindSubgroups thread] DEBUG org.jgroups.protocols.MERGE2 (MERGE2.java:230) - merge task started - run
                2006-02-16 15:00:38,046 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3853 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:38,046 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:490) - first member; cache is empty - getCacheFromCoordinator
                2006-02-16 15:00:38,046 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:340) - created group (first member). My view is [newweb1-staging:3853|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl - becomeSingletonMember
                2006-02-16 15:00:38,046 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:340) - created group (first member). My view is [newweb1-staging:3853|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl - becomeSingletonMember
                2006-02-16 15:00:38,046 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:577) - hdr=I_HAVE_SOCK, mbr=newweb1-staging:3853, sock_addr=newweb1-staging:49153 - sendIHaveSockMessage
                2006-02-16 15:00:38,046 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:577) - hdr=I_HAVE_SOCK, mbr=newweb1-staging:3853, sock_addr=newweb1-staging:49153 - sendIHaveSockMessage
                2006-02-16 15:00:38,046 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.101:30211 (src=newweb1-staging:3853), headers are {FD_SOCK=I_HAVE_SOCK, mbr=newweb1-staging:3853, sock_addr=newweb1-staging:49153, UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                2006-02-16 15:00:38,046 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.101:30211 (src=newweb1-staging:3853), headers are {FD_SOCK=I_HAVE_SOCK, mbr=newweb1-staging:3853, sock_addr=newweb1-staging:49153, UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                2006-02-16 15:00:38,046 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:773) - looped back local message [dst: 231.12.21.101:30211, src: newweb1-staging:3853 (2 headers), size = 0 bytes] - sendUdpMessage
                2006-02-16 15:00:38,046 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:773) - looped back local message [dst: 231.12.21.101:30211, src: newweb1-staging:3853 (2 headers), size = 0 bytes] - sendUdpMessage
                2006-02-16 15:00:38,046 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:186) - i-have-sock: newweb1-staging:3853 --> newweb1-staging:49153 (cache is {newweb1-staging:3853=newweb1-staging:49153}) - up
                2006-02-16 15:00:38,046 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:186) - i-have-sock: newweb1-staging:3853 --> newweb1-staging:49153 (cache is {newweb1-staging:3853=newweb1-staging:49153}) - up
                2006-02-16 15:00:38,046 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:219) - received (mcast) 182 bytes from /192.168.100.45:3854 (size=182 bytes) - run
                2006-02-16 15:00:38,046 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:219) - received (mcast) 182 bytes from /192.168.100.45:3854 (size=182 bytes) - run
                2006-02-16 15:00:38,046 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:707) - discarded own loopback multicast packet - handleMessage
                2006-02-16 15:00:38,046 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:707) - discarded own loopback multicast packet - handleMessage
                2006-02-16 15:00:38,046 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:109) - Starting a new JavaGroups broadcasting listener with properties=UDP(mcast_addr=231.12.21.106;mcast_port=30216;bind_addr=192.168.100.45;ip_ttl=32;mcast_send_buf_size=150000;mcast_recv_buf_size=80000):PING(timeout=2000;num_initial_members=10):MERGE2(min_interval=5000;max_interval=10000):FD_SOCK:VERIFY_SUSPECT(timeout=2000):pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):UNICAST(timeout=300,600,1200,2400):pbcast.STABLE(desired_avg_gossip=20000):FRAG(frag_size=8096;down_thread=false;up_thread=false):pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true) - initialize
                2006-02-16 15:00:38,046 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:109) - Starting a new JavaGroups broadcasting listener with properties=UDP(mcast_addr=231.12.21.106;mcast_port=30216;bind_addr=192.168.100.45;ip_ttl=32;mcast_send_buf_size=150000;mcast_recv_buf_size=80000):PING(timeout=2000;num_initial_members=10):MERGE2(min_interval=5000;max_interval=10000):FD_SOCK:VERIFY_SUSPECT(timeout=2000):pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):UNICAST(timeout=300,600,1200,2400):pbcast.STABLE(desired_avg_gossip=20000):FRAG(frag_size=8096;down_thread=false;up_thread=false):pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true) - initialize
                2006-02-16 15:00:38,062 [thread-pool-24] DEBUG org.jgroups.protocols.AUTOCONF (AUTOCONF.java:165) - frag_size=64000 - senseMaxFragSize
                2006-02-16 15:00:38,062 [thread-pool-24] DEBUG org.jgroups.protocols.AUTOCONF (AUTOCONF.java:165) - frag_size=64000 - senseMaxFragSize
                2006-02-16 15:00:38,062 [thread-pool-24] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl - setImpl
                2006-02-16 15:00:38,062 [thread-pool-24] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl - setImpl
                2006-02-16 15:00:38,062 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:324) - creating sockets and starting threads - start
                2006-02-16 15:00:38,062 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:324) - creating sockets and starting threads - start
                2006-02-16 15:00:38,078 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:866) - unicast sockets will use interface 192.168.100.45 - createSockets
                2006-02-16 15:00:38,078 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:866) - unicast sockets will use interface 192.168.100.45 - createSockets
                2006-02-16 15:00:38,078 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:922) - socket information:
                local_addr=newweb1-staging:3858, mcast_addr=231.12.21.106:30216, bind_addr=/192.168.100.45, ttl=32
                sock: bound to 192.168.100.45:3858, receive buffer size=64000, send buffer size=32000
                mcast_recv_sock: bound to 192.168.100.45:30216, send buffer size=150000, receive buffer size=80000
                mcast_send_sock: bound to 192.168.100.45:3859, send buffer size=150000, receive buffer size=80000 - createSockets
                2006-02-16 15:00:38,078 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:922) - socket information:
                local_addr=newweb1-staging:3858, mcast_addr=231.12.21.106:30216, bind_addr=/192.168.100.45, ttl=32
                sock: bound to 192.168.100.45:3858, receive buffer size=64000, send buffer size=32000
                mcast_recv_sock: bound to 192.168.100.45:30216, send buffer size=150000, receive buffer size=80000
                mcast_send_sock: bound to 192.168.100.45:3859, send buffer size=150000, receive buffer size=80000 - createSockets
                2006-02-16 15:00:38,078 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:1103) - created unicast receiver thread - startThreads
                2006-02-16 15:00:38,078 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:1103) - created unicast receiver thread - startThreads
                2006-02-16 15:00:38,078 [ServerSocketHandler thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:780) - waiting for client connections on port 49154 - run
                2006-02-16 15:00:38,078 [ServerSocketHandler thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:780) - waiting for client connections on port 49154 - run
                2006-02-16 15:00:38,078 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:352) - FIND_INITIAL_MBRS - down
                2006-02-16 15:00:38,078 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:352) - FIND_INITIAL_MBRS - down
                2006-02-16 15:00:38,078 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:315) - pinger_thread started - run
                2006-02-16 15:00:38,078 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:315) - pinger_thread started - run
                2006-02-16 15:00:38,078 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:369) - waiting for initial members: time_to_wait=2000, got 0 rsps - down
                2006-02-16 15:00:38,078 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:369) - waiting for initial members: time_to_wait=2000, got 0 rsps - down
                2006-02-16 15:00:38,078 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.106:30216 (src=newweb1-staging:3858), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                2006-02-16 15:00:38,078 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.106:30216 (src=newweb1-staging:3858), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                2006-02-16 15:00:38,078 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:320) - determinePingDest()=null, pingable_mbrs=[] - run
                2006-02-16 15:00:38,078 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:320) - determinePingDest()=null, pingable_mbrs=[] - run
                2006-02-16 15:00:38,078 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:773) - looped back local message [dst: 231.12.21.106:30216, src: newweb1-staging:3858 (2 headers), size = 0 bytes] - sendUdpMessage
                2006-02-16 15:00:38,078 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:773) - looped back local message [dst: 231.12.21.106:30216, src: newweb1-staging:3858 (2 headers), size = 0 bytes] - sendUdpMessage
                2006-02-16 15:00:38,078 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:359) - pinger thread terminated - run
                2006-02-16 15:00:38,078 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:359) - pinger thread terminated - run
                2006-02-16 15:00:38,078 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:219) - received (mcast) 98 bytes from /192.168.100.45:3859 (size=98 bytes) - run
                2006-02-16 15:00:38,078 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:219) - received (mcast) 98 bytes from /192.168.100.45:3859 (size=98 bytes) - run
                2006-02-16 15:00:38,078 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:707) - discarded own loopback multicast packet - handleMessage
                2006-02-16 15:00:38,078 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:707) - discarded own loopback multicast packet - handleMessage
                2006-02-16 15:00:40,078 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:384) - initial mbrs are [] - down
                2006-02-16 15:00:40,078 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:384) - initial mbrs are [] - down
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:60) - initial_mbrs are [] - join
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:60) - initial_mbrs are [] - join
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:69) - no initial members discovered: creating group as first member - join
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:69) - no initial members discovered: creating group as first member - join
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:306) - [local_addr=newweb1-staging:3858] view is [newweb1-staging:3858|0] [newweb1-staging:3858] - installView
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:306) - [local_addr=newweb1-staging:3858] view is [newweb1-staging:3858|0] [newweb1-staging:3858] - installView
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3858 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:40,078 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:117) - JavaGroups clustering support started successfully - initialize
                2006-02-16 15:00:40,078 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3858 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:40,078 [DownHandler (STABLE)] DEBUG org.jgroups.protocols.pbcast.STABLE (STABLE.java:322) - stable task started; num_gossip_runs=3, max_gossip_runs=3 - startStableTask
                2006-02-16 15:00:40,078 [PullPushAdapterThread] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:184) - A new member at address 'newweb1-staging:3858' has joined the cluster - memberJoined
                2006-02-16 15:00:40,078 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:117) - JavaGroups clustering support started successfully - initialize
                2006-02-16 15:00:40,093 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3858 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:40,078 [DownHandler (STABLE)] DEBUG org.jgroups.protocols.pbcast.STABLE (STABLE.java:322) - stable task started; num_gossip_runs=3, max_gossip_runs=3 - startStableTask
                2006-02-16 15:00:40,078 [PullPushAdapterThread] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:184) - A new member at address 'newweb1-staging:3858' has joined the cluster - memberJoined
                2006-02-16 15:00:40,093 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:251) - VIEW_CHANGE received: [newweb1-staging:3858] - down
                2006-02-16 15:00:40,093 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:251) - VIEW_CHANGE received: [newweb1-staging:3858] - down
                2006-02-16 15:00:40,093 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:490) - first member; cache is empty - getCacheFromCoordinator
                2006-02-16 15:00:40,093 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:490) - first member; cache is empty - getCacheFromCoordinator
                2006-02-16 15:00:40,093 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:577) - hdr=I_HAVE_SOCK, mbr=newweb1-staging:3858, sock_addr=newweb1-staging:49154 - sendIHaveSockMessage
                2006-02-16 15:00:40,093 [DownHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:577) - hdr=I_HAVE_SOCK, mbr=newweb1-staging:3858, sock_addr=newweb1-staging:49154 - sendIHaveSockMessage
                2006-02-16 15:00:40,093 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.106:30216 (src=newweb1-staging:3858), headers are {FD_SOCK=I_HAVE_SOCK, mbr=newweb1-staging:3858, sock_addr=newweb1-staging:49154, UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                2006-02-16 15:00:40,093 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.106:30216 (src=newweb1-staging:3858), headers are {FD_SOCK=I_HAVE_SOCK, mbr=newweb1-staging:3858, sock_addr=newweb1-staging:49154, UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                2006-02-16 15:00:40,093 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:773) - looped back local message [dst: 231.12.21.106:30216, src: newweb1-staging:3858 (2 headers), size = 0 bytes] - sendUdpMessage
                2006-02-16 15:00:40,093 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:773) - looped back local message [dst: 231.12.21.106:30216, src: newweb1-staging:3858 (2 headers), size = 0 bytes] - sendUdpMessage
                2006-02-16 15:00:40,093 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:219) - received (mcast) 182 bytes from /192.168.100.45:3859 (size=182 bytes) - run
                2006-02-16 15:00:40,093 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:219) - received (mcast) 182 bytes from /192.168.100.45:3859 (size=182 bytes) - run
                2006-02-16 15:00:40,093 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:707) - discarded own loopback multicast packet - handleMessage
                2006-02-16 15:00:40,093 [UDP mcast receiver] DEBUG org.jgroups.protocols.UDP (UDP.java:707) - discarded own loopback multicast packet - handleMessage
                2006-02-16 15:00:40,093 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - newweb1-staging:3858 changed role to org.jgroups.protocols.pbcast.CoordGmsImpl - setImpl
                2006-02-16 15:00:40,093 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:340) - created group (first member). My view is [newweb1-staging:3858|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl - becomeSingletonMember
                2006-02-16 15:00:40,093 [DownHandler (GMS)] DEBUG org.jgroups.protocols.pbcast.ClientGmsImpl (ClientGmsImpl.java:340) - created group (first member). My view is [newweb1-staging:3858|0], impl is org.jgroups.protocols.pbcast.CoordGmsImpl - becomeSingletonMember
                2006-02-16 15:00:40,093 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:186) - i-have-sock: newweb1-staging:3858 --> newweb1-staging:49154 (cache is {newweb1-staging:3858=newweb1-staging:49154}) - up
                2006-02-16 15:00:40,093 [UpHandler (FD_SOCK)] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:186) - i-have-sock: newweb1-staging:3858 --> newweb1-staging:49154 (cache is {newweb1-staging:3858=newweb1-staging:49154}) - up
                2006-02-16 15:00:40,093 [MERGE2.FindSubgroups thread] DEBUG org.jgroups.protocols.MERGE2 (MERGE2.java:230) - merge task started - run
                2006-02-16 15:00:40,093 [MERGE2.FindSubgroups thread] DEBUG org.jgroups.protocols.MERGE2 (MERGE2.java:230) - merge task started - run
                2006-02-16 15:00:40,093 [thread-pool-24] WARN com.inno.factory.XMLFileConfigurationManager (?:?) - XML file validation not supported by XML parser. - getDocument
                2006-02-16 15:00:41,953 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:109) - Starting a new JavaGroups broadcasting listener with properties=UDP(mcast_addr=231.12.21.105;mcast_port=30215;bind_addr=192.168.100.45;ip_ttl=32;mcast_send_buf_size=150000;mcast_recv_buf_size=80000):PING(timeout=2000;num_initial_members=10):MERGE2(min_interval=5000;max_interval=10000):FD_SOCK:VERIFY_SUSPECT(timeout=2000):pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):UNICAST(timeout=300,600,1200,2400):pbcast.STABLE(desired_avg_gossip=20000):FRAG(frag_size=8096;down_thread=false;up_thread=false):pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true) - initialize
                2006-02-16 15:00:41,953 [thread-pool-24] INFO com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener (JavaGroupsBroadcastingListener.java:109) - Starting a new JavaGroups broadcasting listener with properties=UDP(mcast_addr=231.12.21.105;mcast_port=30215;bind_addr=192.168.100.45;ip_ttl=32;mcast_send_buf_size=150000;mcast_recv_buf_size=80000):PING(timeout=2000;num_initial_members=10):MERGE2(min_interval=5000;max_interval=10000):FD_SOCK:VERIFY_SUSPECT(timeout=2000):pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):UNICAST(timeout=300,600,1200,2400):pbcast.STABLE(desired_avg_gossip=20000):FRAG(frag_size=8096;down_thread=false;up_thread=false):pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true) - initialize
                2006-02-16 15:00:41,968 [thread-pool-24] DEBUG org.jgroups.protocols.AUTOCONF (AUTOCONF.java:165) - frag_size=64000 - senseMaxFragSize
                2006-02-16 15:00:41,968 [thread-pool-24] DEBUG org.jgroups.protocols.AUTOCONF (AUTOCONF.java:165) - frag_size=64000 - senseMaxFragSize
                2006-02-16 15:00:41,968 [thread-pool-24] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl - setImpl
                2006-02-16 15:00:41,968 [thread-pool-24] DEBUG org.jgroups.protocols.pbcast.GMS (GMS.java:92) - changed role to org.jgroups.protocols.pbcast.ClientGmsImpl - setImpl
                2006-02-16 15:00:41,968 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:324) - creating sockets and starting threads - start
                2006-02-16 15:00:41,968 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:324) - creating sockets and starting threads - start
                2006-02-16 15:00:41,968 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:866) - unicast sockets will use interface 192.168.100.45 - createSockets
                2006-02-16 15:00:41,968 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:866) - unicast sockets will use interface 192.168.100.45 - createSockets
                2006-02-16 15:00:41,984 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:922) - socket information:
                local_addr=newweb1-staging:3863, mcast_addr=231.12.21.105:30215, bind_addr=/192.168.100.45, ttl=32
                sock: bound to 192.168.100.45:3863, receive buffer size=64000, send buffer size=32000
                mcast_recv_sock: bound to 192.168.100.45:30215, send buffer size=150000, receive buffer size=80000
                mcast_send_sock: bound to 192.168.100.45:3864, send buffer size=150000, receive buffer size=80000 - createSockets
                2006-02-16 15:00:41,984 [DownHandler (UDP)] INFO org.jgroups.protocols.UDP (UDP.java:922) - socket information:
                local_addr=newweb1-staging:3863, mcast_addr=231.12.21.105:30215, bind_addr=/192.168.100.45, ttl=32
                sock: bound to 192.168.100.45:3863, receive buffer size=64000, send buffer size=32000
                mcast_recv_sock: bound to 192.168.100.45:30215, send buffer size=150000, receive buffer size=80000
                mcast_send_sock: bound to 192.168.100.45:3864, send buffer size=150000, receive buffer size=80000 - createSockets
                2006-02-16 15:00:41,984 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:1103) - created unicast receiver thread - startThreads
                2006-02-16 15:00:41,984 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:1103) - created unicast receiver thread - startThreads
                2006-02-16 15:00:41,984 [ServerSocketHandler thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:780) - waiting for client connections on port 49155 - run
                2006-02-16 15:00:41,984 [ServerSocketHandler thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:780) - waiting for client connections on port 49155 - run
                2006-02-16 15:00:41,984 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:352) - FIND_INITIAL_MBRS - down
                2006-02-16 15:00:41,984 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:352) - FIND_INITIAL_MBRS - down
                2006-02-16 15:00:41,984 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:315) - pinger_thread started - run
                2006-02-16 15:00:41,984 [FD_SOCK Ping thread] DEBUG org.jgroups.protocols.FD_SOCK (FD_SOCK.java:315) - pinger_thread started - run
                2006-02-16 15:00:41,984 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:369) - waiting for initial members: time_to_wait=2000, got 0 rsps - down
                2006-02-16 15:00:41,984 [DownHandler (PING)] DEBUG org.jgroups.protocols.PING (PING.java:369) - waiting for initial members: time_to_wait=2000, got 0 rsps - down
                2006-02-16 15:00:41,984 [DownHandler (UDP)] DEBUG org.jgroups.protocols.UDP (UDP.java:756) - sending message to 231.12.21.105:30215 (src=newweb1-staging:3863), headers are {PING=[PING: type=GET_MBRS_REQ, arg=null], UDP=[UDP:group_addr=OSCacheBus]} - sendUdpMessage
                20




                While debugging i find these props in the GeneralCacheAdministrator
                {cache.cluster.properties=UDP(mcast_addr=231.12.21.106;mcast_port=30216;bind_addr=192.168.100.51;ip_ttl=32;mcast_send_buf_size=150000;mcast_recv_buf_size=80000):PING(timeout=2000;num_initial_members=10):MERGE2(min_interval=5000;max_interval=10000):FD_SOCK:VERIFY_SUSPECT(timeout=2000):pbcast.NAKACK(gc_lag=50;retransmit_timeout=300,600,1200,2400,4800;max_xmit_size=8192):UNICAST(timeout=300,600,1200,2400):pbcast.STABLE(desired_avg_gossip=20000):FRAG(frag_size=8096;down_thread=false;up_thread=false):pbcast.GMS(join_timeout=10000;join_retry_timeout=4000;shun=true;print_local_addr=true), cache.algorithm=com.opensymphony.oscache.base.algorithm.LRUCache, cache.cluster.use.jgroups=true, gdp.cache.debug=false, gdp.cache.lifetime=900, cache.capacity=100, cache.memory=true, cache.event.listeners=com.opensymphony.oscache.plugins.clustersupport.JavaGroupsBroadcastingListener}


                To flush we use flushEntry method by id of the to flush object

                thanks

                • 5. Re: Listener ignored => ChannelException: unable to setup th
                  Bela Ban Master

                  What exactly doesn't work ? If you can reproduce it, it would be good if you could create a JIRA bug report (http://jira.jboss.com/jira/browse/JGRP) and attach the logs to that case.

                  • 6. Re: Listener ignored => ChannelException: unable to setup th
                    Sven Schauwvliege Newbie

                    the clustering doesnt work.
                    is there a way to see in the logs if jgroups sends the "flush command" out to the other nodes? if so where do i look for?

                    • 7. Re: Listener ignored => ChannelException: unable to setup th
                      Bela Ban Master

                      I assume flush() is an OSCache method ? Then it is probably sent out using RpcDispatcher.callRemoteMethods("flush", ..). I'd either debug that part and set a breakpoint at flush(), or enable TRACE log for org.jgroups.blocks to see debug info for RpcDispatcher