Henrik Karlsson created AMQ-4933:
------------------------------------
Summary: Migration of database fails
Key: AMQ-4933
URL: https://issues.apache.org/jira/browse/AMQ-4933
Project: ActiveMQ
Issue Type: Bug
Affects Versions: 5.9.0
Environment: Windows Server 2008 R2, Java 1.6.45, SQL Server 2008 R2
Reporter: Henrik Karlsson
Getting a lot of errors then starting ActiveMQ after upgrading to 5.9.0.
Some of the are expected, because the table, index or field already exists, but
I also get other errors. More strange is then I don't get any error but it
doesn't work anyway. The statements to add the field XID executes without
error, but the field is not added. It's like the changes are never committed.
2013-12-12 12:00:33,008 | INFO | Using Persistence Adapter:
JDBCPersistenceAdapter(org.apache.commons.dbcp.BasicDataSource@7458e2a1) |
org.apache.activemq.broker.BrokerService | WrapperSimpleAppMain
2013-12-12 12:00:33,453 | INFO | Database adapter driver override recognized
for : [microsoft_jdbc_driver_4_0_for_sql_server] - adapter: class
org.apache.activemq.store.jdbc.adapter.TransactJDBCAdapter |
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,503 | DEBUG | Executing SQL: CREATE TABLE ACTIVEMQ_MSGS(ID
BIGINT NOT NULL, CONTAINER VARCHAR(250), MSGID_PROD VARCHAR(250), MSGID_SEQ
BIGINT, EXPIRATION BIGINT, MSG IMAGE, PRIMARY KEY ( ID ) ) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,796 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE TABLE ACTIVEMQ_MSGS(ID BIGINT NOT
NULL, CONTAINER VARCHAR(250), MSGID_PROD VARCHAR(250), MSGID_SEQ BIGINT,
EXPIRATION BIGINT, MSG IMAGE, PRIMARY KEY ( ID ) ) Message: There is already an
object named 'ACTIVEMQ_MSGS' in the database. SQLState: S0001 Vendor code: 2714
| org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:34,796 | DEBUG | Executing SQL: CREATE INDEX
ACTIVEMQ_MSGS_MIDX ON ACTIVEMQ_MSGS (MSGID_PROD,MSGID_SEQ) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,888 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE INDEX ACTIVEMQ_MSGS_MIDX ON
ACTIVEMQ_MSGS (MSGID_PROD,MSGID_SEQ) Message: The operation failed because an
index or statistics with name 'ACTIVEMQ_MSGS_MIDX' already exists on table
'ACTIVEMQ_MSGS'. SQLState: S0001 Vendor code: 1913 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,888 | DEBUG | Executing SQL: CREATE INDEX
ACTIVEMQ_MSGS_CIDX ON ACTIVEMQ_MSGS (CONTAINER) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,913 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE INDEX ACTIVEMQ_MSGS_CIDX ON
ACTIVEMQ_MSGS (CONTAINER) Message: The operation failed because an index or
statistics with name 'ACTIVEMQ_MSGS_CIDX' already exists on table
'ACTIVEMQ_MSGS'. SQLState: S0001 Vendor code: 1913 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,913 | DEBUG | Executing SQL: CREATE INDEX
ACTIVEMQ_MSGS_EIDX ON ACTIVEMQ_MSGS (EXPIRATION) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,937 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE INDEX ACTIVEMQ_MSGS_EIDX ON
ACTIVEMQ_MSGS (EXPIRATION) Message: The operation failed because an index or
statistics with name 'ACTIVEMQ_MSGS_EIDX' already exists on table
'ACTIVEMQ_MSGS'. SQLState: S0001 Vendor code: 1913 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,937 | DEBUG | Executing SQL: CREATE TABLE
ACTIVEMQ_ACKS(CONTAINER VARCHAR(250) NOT NULL, SUB_DEST VARCHAR(250), CLIENT_ID
VARCHAR(250) NOT NULL, SUB_NAME VARCHAR(250) NOT NULL, SELECTOR VARCHAR(250),
LAST_ACKED_ID BIGINT, PRIMARY KEY ( CONTAINER, CLIENT_ID, SUB_NAME)) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:34,962 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE TABLE ACTIVEMQ_ACKS(CONTAINER
VARCHAR(250) NOT NULL, SUB_DEST VARCHAR(250), CLIENT_ID VARCHAR(250) NOT NULL,
SUB_NAME VARCHAR(250) NOT NULL, SELECTOR VARCHAR(250), LAST_ACKED_ID BIGINT,
PRIMARY KEY ( CONTAINER, CLIENT_ID, SUB_NAME)) Message: There is already an
object named 'ACTIVEMQ_ACKS' in the database. SQLState: S0001 Vendor code: 2714
| org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:34,962 | DEBUG | Executing SQL: ALTER TABLE ACTIVEMQ_MSGS ADD
PRIORITY BIGINT | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,037 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: ALTER TABLE ACTIVEMQ_MSGS ADD PRIORITY
BIGINT Message: Column names in each table must be unique. Column name
'PRIORITY' in table 'ACTIVEMQ_MSGS' is specified more than once. SQLState:
S0004 Vendor code: 2705 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,037 | DEBUG | Executing SQL: CREATE INDEX
ACTIVEMQ_MSGS_PIDX ON ACTIVEMQ_MSGS (PRIORITY) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,060 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE INDEX ACTIVEMQ_MSGS_PIDX ON
ACTIVEMQ_MSGS (PRIORITY) Message: The operation failed because an index or
statistics with name 'ACTIVEMQ_MSGS_PIDX' already exists on table
'ACTIVEMQ_MSGS'. SQLState: S0001 Vendor code: 1913 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,061 | DEBUG | Executing SQL: ALTER TABLE ACTIVEMQ_MSGS ADD
XID VARCHAR(250) | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,110 | DEBUG | Executing SQL: ALTER TABLE ACTIVEMQ_ACKS ADD
PRIORITY BIGINT DEFAULT 5 NOT NULL |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,152 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: ALTER TABLE ACTIVEMQ_ACKS ADD PRIORITY
BIGINT DEFAULT 5 NOT NULL Message: Column names in each table must be unique.
Column name 'PRIORITY' in table 'ACTIVEMQ_ACKS' is specified more than once.
SQLState: S0004 Vendor code: 2705 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,152 | DEBUG | Executing SQL: ALTER TABLE ACTIVEMQ_ACKS ADD
XID VARCHAR(250) | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,175 | DEBUG | Executing SQL: ALTER TABLE ACTIVEMQ_ACKS DROP
PRIMARY KEY | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,204 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: ALTER TABLE ACTIVEMQ_ACKS DROP PRIMARY KEY
Message: Incorrect syntax near the keyword 'PRIMARY'. SQLState: S0001 Vendor
code: 156 | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,204 | DEBUG | Executing SQL: ALTER TABLE ACTIVEMQ_ACKS ADD
PRIMARY KEY (CONTAINER, CLIENT_ID, SUB_NAME, PRIORITY) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,233 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: ALTER TABLE ACTIVEMQ_ACKS ADD PRIMARY KEY
(CONTAINER, CLIENT_ID, SUB_NAME, PRIORITY) Message: Table 'ACTIVEMQ_ACKS'
already has a primary key defined on it. SQLState: S0000 Vendor code: 1779 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,233 | DEBUG | Executing SQL: CREATE INDEX
ACTIVEMQ_MSGS_XIDX ON ACTIVEMQ_MSGS (XID) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,462 | DEBUG | Executing SQL: CREATE INDEX
ACTIVEMQ_ACKS_XIDX ON ACTIVEMQ_ACKS (XID) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,488 | DEBUG | Executing SQL: CREATE TABLE ACTIVEMQ_LOCK( ID
BIGINT NOT NULL, TIME BIGINT, BROKER_NAME VARCHAR(250), PRIMARY KEY (ID) ) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,514 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: CREATE TABLE ACTIVEMQ_LOCK( ID BIGINT NOT
NULL, TIME BIGINT, BROKER_NAME VARCHAR(250), PRIMARY KEY (ID) ) Message: There
is already an object named 'ACTIVEMQ_LOCK' in the database. SQLState: S0001
Vendor code: 2714 | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,514 | DEBUG | Executing SQL: INSERT INTO ACTIVEMQ_LOCK(ID)
VALUES (1) | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,560 | DEBUG | Could not create JDBC tables; The message
table already existed. Failure was: INSERT INTO ACTIVEMQ_LOCK(ID) VALUES (1)
Message: Violation of PRIMARY KEY constraint 'PK__ACTIVEMQ__3214EC2707020F21'.
Cannot insert duplicate key in object 'dbo.ACTIVEMQ_LOCK'. SQLState: 23000
Vendor code: 2627 | org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter |
WrapperSimpleAppMain
2013-12-12 12:00:35,701 | INFO | Database lock driver override recognized for
: [microsoft_jdbc_driver_4_0_for_sql_server] - adapter: class
org.apache.activemq.store.jdbc.adapter.TransactDatabaseLocker |
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,701 | INFO | Using a separate dataSource for locking:
org.apache.commons.dbcp.BasicDataSource@7458e2a1 |
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | WrapperSimpleAppMain
2013-12-12 12:00:35,701 | INFO | Attempting to acquire the exclusive lock to
become the Master broker |
org.apache.activemq.store.jdbc.adapter.TransactDatabaseLocker |
WrapperSimpleAppMain
2013-12-12 12:00:35,777 | INFO | Becoming the master on dataSource:
org.apache.commons.dbcp.BasicDataSource@7458e2a1 |
org.apache.activemq.store.jdbc.adapter.TransactDatabaseLocker |
WrapperSimpleAppMain
2013-12-12 12:00:35,780 | DEBUG | Cleaning up old messages. |
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | ActiveMQ JDBC PA
Scheduled Task
2013-12-12 12:00:35,781 | DEBUG | Executing SQL: DELETE FROM ACTIVEMQ_MSGS
WHERE (PRIORITY=? AND ID <= ( SELECT min(ACTIVEMQ_ACKS.LAST_ACKED_ID)
FROM ACTIVEMQ_ACKS WHERE ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER
AND ACTIVEMQ_ACKS.PRIORITY=?) ) |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | ActiveMQ JDBC PA
Scheduled Task
2013-12-12 12:00:35,964 | DEBUG | Deleted 0 old message(s) at priority: 0 |
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter | ActiveMQ JDBC PA
Scheduled Task
2013-12-12 12:00:35,964 | DEBUG | Cleanup done. |
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | ActiveMQ JDBC PA
Scheduled Task
2013-12-12 12:00:36,554 | INFO | Apache ActiveMQ 5.9.0 (PIGBG2447HENKAR,
PIGBG2447HENKAR) is starting | org.apache.activemq.broker.BrokerService |
WrapperSimpleAppMain
2013-12-12 12:00:36,607 | WARN | JDBC Failure: Invalid column name 'XID'. |
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter | WrapperSimpleAppMain
com.microsoft.sqlserver.jdbc.SQLServerException: Invalid column name 'XID'.
at
com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:216)
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1515)
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:404)
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:350)
at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:5696)
at
com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1715)
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:180)
at
com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:155)
at
com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.executeQuery(SQLServerPreparedStatement.java:285)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
at
org.apache.activemq.store.jdbc.adapter.DefaultJDBCAdapter.doRecoverPreparedOps(DefaultJDBCAdapter.java:965)
at
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.recover(JDBCPersistenceAdapter.java:764)
at
org.apache.activemq.store.jdbc.JdbcMemoryTransactionStore.recover(JdbcMemoryTransactionStore.java:160)
at
org.apache.activemq.broker.TransactionBroker.start(TransactionBroker.java:97)
at
org.apache.activemq.broker.BrokerService$5.start(BrokerService.java:2144)
at
org.apache.activemq.broker.BrokerService.doStartBroker(BrokerService.java:648)
at
org.apache.activemq.broker.BrokerService.startBroker(BrokerService.java:632)
at
org.apache.activemq.broker.BrokerService.start(BrokerService.java:568)
at
org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrokerService.java:73)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1608)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1549)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1479)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:521)
at
org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:458)
at
org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:295)
at
org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:223)
at
org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:292)
at
org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:194)
at
org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:628)
at
org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:932)
at
org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:479)
at
org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:64)
at
org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(ResourceXmlApplicationContext.java:52)
at
org.apache.activemq.xbean.XBeanBrokerFactory$1.<init>(XBeanBrokerFactory.java:104)
at
org.apache.activemq.xbean.XBeanBrokerFactory.createApplicationContext(XBeanBrokerFactory.java:104)
at
org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFactory.java:67)
at
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:71)
at
org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:54)
at
org.apache.activemq.console.command.StartCommand.runTask(StartCommand.java:87)
at
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
at
org.apache.activemq.console.command.ShellCommand.runTask(ShellCommand.java:150)
at
org.apache.activemq.console.command.AbstractCommand.execute(AbstractCommand.java:57)
at
org.apache.activemq.console.command.ShellCommand.main(ShellCommand.java:104)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.activemq.console.Main.runTaskClass(Main.java:262)
at org.apache.activemq.console.Main.main(Main.java:115)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:240)
at java.lang.Thread.run(Thread.java:662)
2013-12-12 12:00:36,651 | ERROR | Failed to start Apache ActiveMQ
([PIGBG2447HENKAR, PIGBG2447HENKAR], java.io.IOException: Failed to recover
from: org.apache.activemq.store.jdbc.JdbcMemoryTransactionStore@24bb6086.
Reason: com.microsoft.sqlserver.jdbc.SQLServerException: Invalid column name
'XID'.) | org.apache.activemq.broker.BrokerService | WrapperSimpleAppMain
--
This message was sent by Atlassian JIRA
(v6.1.4#6159)
