8 Replies Latest reply on Mar 30, 2016 10:43 AM by mnovak

    HQ222137: Unable to announce backup, retrying

    ajitiitr

      We are attempting to get a Live-Backup configuration deployed on two distinct servers.I am using Jboss wildfly 8.2.0 final . We have been using the user guide and examples to assist with my configuration, however we have run into a problem that I haven't been able to resolve. With the attached configuration, my Live server starts up without any problems. However, when I startup my Backup server, I get a warning stating "Unable to announce backup" with the following exception:

       

      Line 1057: 08:31:55,635 WARN [org.hornetq.core.server] (Thread-0 (HornetQ-server-HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872-600430445)) HQ222137: Unable to announce backup, retrying



        • 1. Re: HQ222137: Unable to announce backup, retrying
          jbertram

          Can you attach your live and backup server configurations?

           

          Is there a particular reason you're using Wildfly 8.2 rather than something more recent like 10?

          • 2. Re: HQ222137: Unable to announce backup, retrying
            ajitiitr

            Hi Justin,

            thanks for reply.

            yes It is a customer requirement. and its only happening for uni-cast configuration.please find the standalone.xml in attachment for both the servers.


            • 3. Re: HQ222137: Unable to announce backup, retrying
              jbertram

              The HornetQ configuration looks OK as far as I can tell aside from what appears to be superfluous "dg-group2" and "bg-group2" definitions on the live servers.  That said, I can't really comment on the JGroups configuration since I'm not terribly familiar with that.  My hunch is that something is incorrectly configured there.  You might try using a static clustering configuration which is like JGroups TCP but doesn't use JGroups at all.  See the documentation for more details on that.

               

              Is there a stack-trace associated with the WARN message or any other indication of what the underlying problem might be?

               

              yes It is a customer requirement.

              OK.  Any idea why it is a customer requirement?

              • 4. Re: HQ222137: Unable to announce backup, retrying
                ajitiitr

                Hi Justin,

                 

                there is no Stack trace warning only this message is coming repeatedly.

                Logs for hornetq on node 1:

                ------------------------------------------------------------------------------

                                         NODE1

                -----------------------------------------------------------------------------

                 

                Line 160: 09:18:10,320 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221000: backup server is starting with configuration HornetQ Configuration (clustered=true,backup=true,sharedStore=true,journalDirectory=\\Sinaj03-w71\jbossclst\Node2\journal,bindingsDirectory=\\Sinaj03-w71\jbossclst\Node2\bindings,largeMessagesDirectory=\\Sinaj03-w71\jbossclst\Node2\large-messages,pagingDirectory=\\Sinaj03-w71\jbossclst\Node2\paging)
                Line 161: 09:18:10,383 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221032: Waiting to become backup node
                Line 162: 09:18:10,414 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221033: ** got backup lock
                Line 163: 09:18:10,508 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221013: Using NIO Journal
                Line 165: 09:18:10,757 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221043: Adding protocol support CORE
                Line 166: 09:18:10,788 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221043: Adding protocol support AMQP
                Line 167: 09:18:10,804 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221043: Adding protocol support STOMP
                Line 168: 09:18:11,787 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221000: live server is starting with configuration HornetQ Configuration (clustered=true,backup=false,sharedStore=true,journalDirectory=\\Sinaj03-w71\jbossclst\Node1\journal,bindingsDirectory=\\Sinaj03-w71\jbossclst\Node1\bindings,largeMessagesDirectory=\\Sinaj03-w71\jbossclst\Node1\large-messages,pagingDirectory=\\Sinaj03-w71\jbossclst\Node1\paging)
                Line 169: 09:18:11,802 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221006: Waiting to obtain live lock
                Line 170: 09:18:11,818 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221013: Using NIO Journal
                Line 171: 09:18:11,834 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221043: Adding protocol support CORE
                Line 172: 09:18:11,896 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221043: Adding protocol support AMQP
                Line 173: 09:18:11,927 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221043: Adding protocol support STOMP
                Line 174: 09:18:12,256 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221034: Waiting to obtain live lock
                Line 175: 09:18:12,287 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221035: Live Server Obtained live lock
                Line 176: 09:18:12,349 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221109: HornetQ Backup Server version 2.4.5.FINAL (Wild Hornet, 124) [a4f6e559-e462-11e5-b3d3-31de099ef10c] started, waiting live to fail before it gets active
                Line 933: 09:18:27,498 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221019: Deleting unreferenced message id=68,721,529,764 from the journal
                Line 981: 09:18:41,508 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221020: Started Netty Acceptor version unknown 10.131.119.198:5455
                Line 982: 09:18:41,711 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221020: Started Netty Acceptor version unknown 10.131.119.198:5445
                Line 988: 09:18:43,568 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221020: Started Netty Acceptor version unknown 10.131.119.198:5456
                Line 994: 09:18:43,677 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221020: Started Netty Acceptor version unknown 10.131.119.198:5446
                Line 995: 09:18:43,786 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221010: Backup Server is now live
                Line 996: 09:18:44,816 INFO  [org.hornetq.core.server] (Thread-1 (HornetQ-scheduled-threads-1235312501)) HQ221008: live server wants to restart, restarting server in backup
                Line 997: 09:18:45,939 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221007: Server is now live
                Line 998: 09:18:45,939 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221001: HornetQ Server version 2.4.5.FINAL (Wild Hornet, 124) [366e905b-e52e-11e5-ad22-b77110151872]
                Line 1000: 09:18:46,079 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 69) HQ221003: trying to deploy queue jms.queue.liveNotificationQ
                Line 1003: 09:18:46,298 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 85) HQ221003: trying to deploy queue jms.topic.cacheEventsT
                Line 1006: 09:18:46,376 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 74) HQ221003: trying to deploy queue jms.topic.testTopic
                Line 1009: 09:18:46,423 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 84) HQ221003: trying to deploy queue jms.queue.testQueue
                Line 1013: 09:18:46,688 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 71) HQ221003: trying to deploy queue jms.queue.wftmsQ
                Line 1016: 09:18:46,969 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 62) HQ221003: trying to deploy queue jms.queue.eurekifyTestQ
                Line 1021: 09:18:47,016 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 79) HQ221003: trying to deploy queue jms.queue.wpUtilQueue
                Line 1025: 09:18:47,078 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 83) HQ221003: trying to deploy queue jms.queue.wfAsyncQ
                Line 1028: 09:18:47,234 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 76) HQ221003: trying to deploy queue jms.queue.fixAlertsExecutorQ
                Line 1034: 09:18:47,374 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 70) HQ221003: trying to deploy queue jms.queue.wpEventQueue
                Line 1037: 09:18:47,390 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 73) HQ221003: trying to deploy queue jms.queue.DLQ
                Line 1039: 09:18:47,421 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 68) HQ221003: trying to deploy queue jms.queue.txLogQ
                Line 1042: 09:18:47,484 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 81) HQ221003: trying to deploy queue jms.queue.wpServAutoActQueue
                Line 1049: 09:18:47,858 INFO  [org.hornetq.core.server] (Thread-145) HQ221002: HornetQ Server version 2.4.5.FINAL (Wild Hornet, 124) [a4f6e559-e462-11e5-b3d3-31de099ef10c] stopped
                Line 1050: 09:18:52,866 INFO  [org.hornetq.core.server] (Thread-145) HQ221000: backup server is starting with configuration HornetQ Configuration (clustered=true,backup=true,sharedStore=true,journalDirectory=\\Sinaj03-w71\jbossclst\Node2\journal,bindingsDirectory=\\Sinaj03-w71\jbossclst\Node2\bindings,largeMessagesDirectory=\\Sinaj03-w71\jbossclst\Node2\large-messages,pagingDirectory=\\Sinaj03-w71\jbossclst\Node2\paging)
                Line 1051: 09:18:52,897 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221032: Waiting to become backup node
                Line 1052: 09:18:53,038 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221033: ** got backup lock
                Line 1053: 09:18:53,053 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221013: Using NIO Journal
                Line 1054: 09:18:53,053 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221043: Adding protocol support CORE
                Line 1055: 09:18:53,069 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221043: Adding protocol support AMQP
                Line 1056: 09:18:53,116 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221043: Adding protocol support STOMP
                Line 1057: 09:18:53,303 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c) HQ221109: HornetQ Backup Server version 2.4.5.FINAL (Wild Hornet, 124) [a4f6e559-e462-11e5-b3d3-31de099ef10c] started, waiting live to fail before it gets active
                Line 1058: 09:18:53,318 WARN  [org.hornetq.core.server] (Thread-0 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1059: 09:18:54,020 WARN  [org.hornetq.core.server] (Thread-1 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1061: 09:18:54,535 WARN  [org.hornetq.core.server] (Thread-2 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1062: 09:18:55,050 WARN  [org.hornetq.core.server] (Thread-3 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1063: 09:18:55,565 WARN  [org.hornetq.core.server] (Thread-4 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1064: 09:18:56,079 WARN  [org.hornetq.core.server] (Thread-5 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1065: 09:18:56,594 WARN  [org.hornetq.core.server] (Thread-6 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1066: 09:18:57,125 WARN  [org.hornetq.core.server] (Thread-7 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying
                Line 1067: 09:18:57,640 WARN  [org.hornetq.core.server] (Thread-8 (HornetQ-server-HornetQServerImpl::serverUUID=a4f6e559-e462-11e5-b3d3-31de099ef10c-805615830)) HQ222137: Unable to announce backup, retrying

                 

                -------------------------------------------------------------------------

                             Node 2

                --------------------------------------------------------------------------

                 

                Line 162: 09:18:20,655 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 60) HQ221000: backup server is starting with configuration HornetQ Configuration (clustered=true,backup=true,sharedStore=true,journalDirectory=\\Sinaj03-w71\jbossclst\Node1\journal,bindingsDirectory=\\Sinaj03-w71\jbossclst\Node1\bindings,largeMessagesDirectory=\\Sinaj03-w71\jbossclst\Node1\large-messages,pagingDirectory=\\Sinaj03-w71\jbossclst\Node1\paging)

                  Line 163: 09:18:20,718 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221000: live server is starting with configuration HornetQ Configuration (clustered=true,backup=false,sharedStore=true,journalDirectory=\\Sinaj03-w71\jbossclst\Node2\journal,bindingsDirectory=\\Sinaj03-w71\jbossclst\Node2\bindings,largeMessagesDirectory=\\Sinaj03-w71\jbossclst\Node2\large-messages,pagingDirectory=\\Sinaj03-w71\jbossclst\Node2\paging)

                  Line 164: 09:18:22,262 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221006: Waiting to obtain live lock

                  Line 165: 09:18:22,933 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221032: Waiting to become backup node

                  Line 166: 09:18:22,949 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221033: ** got backup lock

                  Line 167: 09:18:23,027 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221013: Using NIO Journal

                  Line 168: 09:18:23,027 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221013: Using NIO Journal

                  Line 170: 09:18:31,888 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221043: Adding protocol support CORE

                  Line 171: 09:18:31,888 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221043: Adding protocol support CORE

                  Line 172: 09:18:32,044 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221043: Adding protocol support AMQP

                  Line 173: 09:18:32,044 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221043: Adding protocol support AMQP

                  Line 174: 09:18:32,059 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221043: Adding protocol support STOMP

                  Line 175: 09:18:32,059 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221043: Adding protocol support STOMP

                  Line 176: 09:18:32,232 INFO  [org.hornetq.core.server] (HQ119000: Activation for server HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872) HQ221109: HornetQ Backup Server version 2.4.5.FINAL (Wild Hornet, 124) [366e905b-e52e-11e5-ad22-b77110151872] started, waiting live to fail before it gets active

                  Line 187: 09:18:37,444 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221034: Waiting to obtain live lock

                  Line 188: 09:18:47,477 INFO  [org.hornetq.core.server] (Thread-0 (HornetQ-server-HornetQServerImpl::serverUUID=366e905b-e52e-11e5-ad22-b77110151872-2129091247)) HQ221031: backup announced

                  Line 189: 09:18:47,914 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221035: Live Server Obtained live lock

                  Line 220: 09:19:07,623 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221020: Started Netty Acceptor version unknown 10.131.119.231:5455

                  Line 222: 09:19:07,920 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221020: Started Netty Acceptor version unknown 10.131.119.231:5445

                  Line 366: 09:19:08,591 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221007: Server is now live

                  Line 384: 09:19:08,606 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 61) HQ221001: HornetQ Server version 2.4.5.FINAL (Wild Hornet, 124) [a4f6e559-e462-11e5-b3d3-31de099ef10c]

                  Line 402: 09:19:08,716 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 66) HQ221003: trying to deploy queue jms.queue.wfAsyncQ

                  Line 507: 09:19:08,840 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 75) HQ221003: trying to deploy queue jms.topic.testTopic

                  Line 579: 09:19:08,918 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 74) HQ221003: trying to deploy queue jms.topic.cacheEventsT

                  Line 669: 09:19:09,028 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 73) HQ221003: trying to deploy queue jms.queue.testQueue

                  Line 796: 09:19:09,340 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 65) HQ221003: trying to deploy queue jms.queue.wpEventQueue

                  Line 850: 09:19:09,418 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 72) HQ221003: trying to deploy queue jms.queue.fixAlertsExecutorQ

                  Line 904: 09:19:09,511 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 63) HQ221003: trying to deploy queue jms.queue.wpServAutoActQueue

                  Line 962: 09:19:09,621 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 71) HQ221003: trying to deploy queue jms.queue.liveNotificationQ

                  Line 987: 09:19:09,730 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 67) HQ221003: trying to deploy queue jms.queue.wftmsQ

                  Line 994: 09:19:09,792 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 69) HQ221003: trying to deploy queue jms.queue.wpUtilQueue

                  Line 998: 09:19:09,948 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 70) HQ221003: trying to deploy queue jms.queue.txLogQ

                  Line 1001: 09:19:10,011 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 64) HQ221003: trying to deploy queue jms.queue.DLQ

                  Line 1003: 09:19:10,058 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 62) HQ221003: trying to deploy queue jms.queue.eurekifyTestQ

                 

                 

                ----------------------------------------------------------------------------------------

                 

                thanks,

                Ajit Singh

                • 5. Re: HQ222137: Unable to announce backup, retrying
                  jbertram

                  Is this with JGroups or static cluster configuration?

                  • 6. Re: HQ222137: Unable to announce backup, retrying
                    ajitiitr

                    its JGroups configuration.

                    • 7. Re: HQ222137: Unable to announce backup, retrying
                      jbertram

                      Can you try using a static configuration as I mentioned previously (i.e. eliminate JGroups from the the HornetQ cluster configuration)?

                      • 8. Re: HQ222137: Unable to announce backup, retrying
                        mnovak

                        From the server.log above I don't see that live servers create cluster.

                         

                        I've checked the attached configuration. There is different jgroups-channel for each pair. All 4 HornetQ servers (2 lives and 2 backups) must be in the same cluster. Could you try to unify the jgroups-channel name?