You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@activemq.apache.org by "Jean-Baptiste Onofré (Jira)" <ji...@apache.org> on 2022/08/01 04:26:00 UTC

[jira] [Commented] (AMQ-9013) ERROR | XXXX, no longer able to keep the exclusive lock so giving up being a master

    [ https://issues.apache.org/jira/browse/AMQ-9013?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17573535#comment-17573535 ] 

Jean-Baptiste Onofré commented on AMQ-9013:
-------------------------------------------

Can you please share the lock configuration in your {{activeemq.xml}} ? Especially if you have a lease.

>  ERROR | XXXX, no longer able to keep the exclusive lock so giving up being a master
> ------------------------------------------------------------------------------------
>
>                 Key: AMQ-9013
>                 URL: https://issues.apache.org/jira/browse/AMQ-9013
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: JDBC
>    Affects Versions: 5.9.0
>         Environment: cat activemq.xml
> <!-- START SNIPPET: example -->
> <beans
>   xmlns="http://www.springframework.org/schema/beans"
>   xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
>   xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd
>   http://activemq.apache.org/schema/core http://activemq.apache.org/schema/core/activemq-core.xsd">
>     <!-- Allows us to use system properties as variables in this configuration file -->
>     <bean class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
>         <property name="locations">
>             <value>file:${activemq.conf}/credentials.properties</value>
>         </property>
>     </bean>
>    <!-- Allows accessing the server log -->
>     <bean id="logQuery" class="org.fusesource.insight.log.log4j.Log4jLogQuery"
>           lazy-init="false" scope="singleton"
>           init-method="start" destroy-method="stop">
>     </bean>
>     <!--
>         The <broker> element is used to configure the ActiveMQ broker.
>     -->
>     <broker xmlns="http://activemq.apache.org/schema/core" brokerName="xxxx01" dataDirectory="${activemq.data}">
>         <destinationPolicy>
>             <policyMap>
>               <policyEntries>
>                 <policyEntry topic=">" >
>                     <!-- The constantPendingMessageLimitStrategy is used to prevent
>                          slow topic consumers to block producers and affect other consumers
>                          by limiting the number of messages that are retained
>                          For more information, see:
>                          http://activemq.apache.org/slow-consumer-handling.html
>                     -->
>                   <pendingMessageLimitStrategy>
>                     <constantPendingMessageLimitStrategy limit="1000"/>
>                   </pendingMessageLimitStrategy>
>                 </policyEntry>
>               </policyEntries>
>             </policyMap>
>         </destinationPolicy>
>         <managementContext>
>             <managementContext createConnector="true" connectorPort="10616" connectorHost="10.x.x.x"/>
>         </managementContext>
>         <persistenceAdapter>
>             <jdbcPersistenceAdapter dataDirectory="${activemq.data}" dataSource="#oracle-ds" lockKeepAlivePeriod="3000">
>                 <locker>
>                     <lease-database-locker lockAcquireSleepInterval="4000"/>
>                 </locker>
>             </jdbcPersistenceAdapter>
>         </persistenceAdapter>
>         <systemUsage>
>             <systemUsage>
>                 <memoryUsage>
>                     <memoryUsage percentOfJvmHeap="70" />
>                 </memoryUsage>
>                 <storeUsage>
>                     <storeUsage limit="100 gb"/>
>                 </storeUsage>
>                 <tempUsage>
>                     <tempUsage limit="50 gb"/>
>                 </tempUsage>
>             </systemUsage>
>         </systemUsage>
>         <transportConnectors>
>             <transportConnector name="openwire" uri="tcp://0.0.0.0:61616?maximumConnections=1000&amp;wireFormat.maxFrameSize=104857600"/>
>         </transportConnectors>
>         <!-- destroy the spring context on shutdown to stop jetty -->
>         <shutdownHooks>
>             <bean xmlns="http://www.springframework.org/schema/beans" class="org.apache.activemq.hooks.SpringContextHook" />
>         </shutdownHooks>
>     </broker>
>     <bean id="oracle-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
>         <property name="driverClassName" value="oracle.jdbc.driver.OracleDriver"/>
>         <property name="url" value="jdbc:oracle:thin:@//x.x.x.x:1521/amqdb"/>
>         <property name="username" value="xxxxx"/>
>         <property name="password" value="xxxxxx"/>
>         <property name="poolPreparedStatements" value="true"/>
>     </bean>
>     <import resource="jetty.xml"/>
> </beans>
> <!-- END SNIPPET: example -->
>  
>            Reporter: DannyChan
>            Priority: Major
>         Attachments: image-2022-08-01-09-04-31-857.png
>
>
> In our production environment, ActiveMQ often restarts randomly. Refer to official documents for configuration JDBC Master Slave. Twice failover in half an hour. check vm and oracle healthy in during failover,please analyze the problem, thanks
>  
> xxxx1 activemq log:
> first failover
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | xxxx1 Lease held by xxxx2 till Sun Jul 31 16:25:03 CST 2022
> INFO   | jvm 1    | 2022/07/31 16:25:01 | ERROR | xxxx1, no longer able to keep the exclusive lock so giving up being a master
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | Apache ActiveMQ 5.9.0 (xxxx1, ID:xxxx1-50824-1658747295825-0:1) is shutting down
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Connector openwire stopped
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | PListStore:[/home/apache-activemq-5.9.0/bin/linux-x86-64/../../data/xxxx1/tmp_storage] stopped
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Apache ActiveMQ 5.9.0 (xxxx1, ID:xxxx1-50824-1658747295825-0:1) uptime 11 days 13 hours
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Apache ActiveMQ 5.9.0 (xxxx1, ID:xxxx1-50824-1658747295825-0:1) is shutdown
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Closing org.apache.activemq.xbean.XBeanBrokerFactory$1@6415d653: startup date [Wed Jul 20 03:15:12 CST 2022]; root of context hierarchy
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Destroying Spring FrameworkServlet 'dispatcher'
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Destroying hawtio authentication filter
> INFO   | jvm 1    | 2022/07/31 16:25:03 | Restarting broker
> INFO   | jvm 1    | 2022/07/31 16:25:03 | Loading message broker from: xbean:activemq.xml
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@294574e5: startup date [Sun Jul 31 16:25:03 CST 2022]; root of context hierarchy
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | PListStore:[/home/apache-activemq-5.9.0/bin/linux-x86-64/../../data/xxxx1/tmp_storage] started
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Using Persistence Adapter: JDBCPersistenceAdapter(org.apache.commons.dbcp.BasicDataSource@9158362)
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | JMX consoles can connect to service:jmx:rmi:///jndi/rmi://x.x.x.x:10616/jmxrmi
> INFO   | jvm 1    | 2022/07/31 16:25:03 |  INFO | Database adapter driver override recognized for : [oracle_jdbc_driver] - adapter: class org.apache.activemq.store.jdbc.adapter.OracleJDBCAdapter
> INFO   | jvm 1    | 2022/07/31 16:25:15 |  INFO | xxxx1 attempting to acquire exclusive lease to become the master
> INFO   | jvm 1    | 2022/07/31 16:25:15 |  INFO | xxxx1 Lease held by xxxx2 till Sun Jul 31 16:25:17 CST 2022
> INFO   | jvm 1    | 2022/07/31 16:25:15 |  INFO | xxxx1 failed to acquire lease.  Sleeping for 4000 milli(s) before trying again...
> second failover
> INFO   | jvm 1    | 2022/07/31 16:37:16 |  INFO | xxxx1 Lease held by xxxx2 till Sun Jul 31 16:37:20 CST 2022
> INFO   | jvm 1    | 2022/07/31 16:37:16 |  INFO | xxxx1 failed to acquire lease.  Sleeping for 4000 milli(s) before trying again...
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | xxxx1, becoming master with lease expiry Sun Jul 31 16:37:20 CST 2022 on dataSource: org.apache.commons.dbcp.BasicDataSource@9158362
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Apache ActiveMQ 5.9.0 (xxxx1, ID:xxxx01-50824-1658747295825-0:2) is starting
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Listening for connections at: tcp://xxxx01:61616?maximumConnections=1000&wireFormat.maxFrameSize=104857600
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Connector openwire started
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Apache ActiveMQ 5.9.0 (xxxx1, ID:xxxx01-50824-1658747295825-0:2) started
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | For help or more information please see: http://activemq.apache.org
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Welcome to hawtio 1.2-M23 : http://hawt.io/ : Don't cha wish your console was hawt like me? ;-)
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Starting hawtio authentication filter, JAAS realm: "activemq" authorized role: "admins" role principal classes: "org.apache.activemq.jaas.GroupPrincipal"
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Using file upload directory: /tmp/uploads
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | jolokia-agent: Using access restrictor classpath:/jolokia-access.xml
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | ActiveMQ WebConsole available at http://localhost:8151/
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Initializing Spring FrameworkServlet 'dispatcher'
> xxxx2 activemq log:
> first failover
> INFO   | jvm 1    | 2022/07/31 16:24:56 |  INFO | xxxx2 failed to acquire lease.  Sleeping for 4000 milli(s) before trying again...
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | xxxx2, becoming master with lease expiry Sun Jul 31 16:24:59 CST 2022 on dataSource: org.apache.commons.dbcp.BasicDataSource@60b25aef
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | Apache ActiveMQ 5.9.0 (xxxx2, ID:xxxx202-42432-1658258111781-0:2) is starting
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | Listening for connections at: tcp://xxxx202:61616?maximumConnections=1000&wireFormat.maxFrameSize=104857600
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | Connector openwire started
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | Apache ActiveMQ 5.9.0 (xxxx2, ID:xxxx202-42432-1658258111781-0:2) started
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  INFO | For help or more information please see: http://activemq.apache.org
> INFO   | jvm 1    | 2022/07/31 16:25:01 |  WARN | Store limit is 102400 mb, whilst the data directory: /home/apache-activemq-5.9.0/bin/linux-x86-64/../../data only has 102006 mb of usable space - resetting to maximum available disk space: 102006 mb
> INFO   | jvm 1    | 2022/07/31 16:25:02 |  INFO | Welcome to hawtio 1.2-M23 : http://hawt.io/ : Don't cha wish your console was hawt like me? ;-)
> INFO   | jvm 1    | 2022/07/31 16:25:02 |  INFO | Starting hawtio authentication filter, JAAS realm: "activemq" authorized role: "admins" role principal classes: "org.apache.activemq.jaas.GroupPrincipal"
> INFO   | jvm 1    | 2022/07/31 16:25:02 |  INFO | Using file upload directory: /tmp/uploads
> INFO   | jvm 1    | 2022/07/31 16:25:02 |  INFO | jolokia-agent: Using access restrictor classpath:/jolokia-access.xml
> INFO   | jvm 1    | 2022/07/31 16:25:02 |  INFO | ActiveMQ WebConsole available at http://localhost:8151/
> INFO   | jvm 1    | 2022/07/31 16:25:02 |  INFO | Initializing Spring FrameworkServlet 'dispatcher'
> second failover
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | xxxx2 Lease held by xxxx1 till Sun Jul 31 16:37:24 CST 2022
> INFO   | jvm 1    | 2022/07/31 16:37:20 | ERROR | xxxx2, no longer able to keep the exclusive lock so giving up being a master
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Apache ActiveMQ 5.9.0 (xxxx2, ID:xxxx02-42432-1658258111781-0:2) is shutting down
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Connector openwire stopped
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | PListStore:[/home/xxxx/apache-activemq-5.9.0/bin/linux-x86-64/../../data/xxxx2/tmp_storage] stopped
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Apache ActiveMQ 5.9.0 (xxxx2, ID:xxxx02-42432-1658258111781-0:2) uptime 5 days 21 hours
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Apache ActiveMQ 5.9.0 (xxxx2, ID:xxxx02-42432-1658258111781-0:2) is shutdown
> INFO   | jvm 1    | 2022/07/31 16:37:20 |  INFO | Closing org.apache.activemq.xbean.XBeanBrokerFactory$1@6735523a: startup date [Mon Jul 25 19:08:17 CST 2022]; root of context hierarchy
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Destroying Spring FrameworkServlet 'dispatcher'
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Destroying hawtio authentication filter
> INFO   | jvm 1    | 2022/07/31 16:37:21 | Restarting broker
> INFO   | jvm 1    | 2022/07/31 16:37:21 | Loading message broker from: xbean:activemq.xml
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Refreshing org.apache.activemq.xbean.XBeanBrokerFactory$1@4adb323: startup date [Sun Jul 31 16:37:21 CST 2022]; root of context hierarchy
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | PListStore:[/home/apache-activemq-5.9.0/bin/linux-x86-64/../../data/xxxx2/tmp_storage] started
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Using Persistence Adapter: JDBCPersistenceAdapter(org.apache.commons.dbcp.BasicDataSource@1da39517)
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | JMX consoles can connect to service:jmx:rmi:///jndi/rmi://x.x.x.x:10616/jmxrmi
> INFO   | jvm 1    | 2022/07/31 16:37:21 |  INFO | Database adapter driver override recognized for : [oracle_jdbc_driver] - adapter: class org.apache.activemq.store.jdbc.adapter.OracleJDBCAdapter
> INFO   | jvm 1    | 2022/07/31 16:37:26 |  INFO | xxxx2 attempting to acquire exclusive lease to become the master
> INFO   | jvm 1    | 2022/07/31 16:37:26 |  INFO | xxxx2 Lease held by xxxx1 till Sun Jul 31 16:37:27 CST 2022
> INFO   | jvm 1    | 2022/07/31 16:37:26 |  INFO | xxxx2 failed to acquire lease.  Sleeping for 4000 milli(s) before trying again...
> cpu & memory usage:
> !image-2022-08-01-09-04-31-857.png!
> network:
> no dropped no errors
>  



--
This message was sent by Atlassian Jira
(v8.20.10#820010)