The interesting line in the stack trace is org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getLastMessageBrokerSequenceId(). (The 5.11.1 version of that code is at http://grepcode.com/file/repo1.maven.org/maven2/org.apache.activemq/activemq-jdbc-store/5.11.1/org/apache/activemq/store/jdbc/JDBCPersistenceAdapter.java; 5.12.0 doesn't appear to be in GrepCode yet, but presumably it's very similar if not identical for that method.)
It looks like it's trying to read an existing (5.11.1) message from the store and deciding it can't be unmarshalled properly. That implies that either you got really unlucky and the 5.11.1 wrote a corrupted message just before you shut it down (unlikely) or the Openwire format is incompatible between 5.11.1 and 5.12.0 (which isn't supposed to happen and would be a big problem IMO) or Openwire itself is compatible but there's a bug causing it to behave incorrectly or causing us to read the message's bytes incorrectly. The 5.12.0 release notes ( http://activemq.apache.org/activemq-5120-release.html) don't call out any incompatibility, and the list of fixes ( https://issues.apache.org/jira/secure/ReleaseNote.jspa?projectId=12311210&version=12329258) doesn't include anything that jumps out at me as explaining this behavior. Does anyone have any background on any changes that might be relevant here? Can you download the 5.12.0 code and attach a debugger with a breakpoint on that line to see if you're at least getting bytes in the array? An easy workaround would be to delete all messages from the database, but I'd like to troubleshoot this so we figure out what's going on, so if you do that, can you copy the database to a test instance so we can keep investigating? Tim On Sep 12, 2015 8:13 AM, "Weatherby,Gerard" <gweathe...@uchc.edu> wrote: > Total guess; I'd look at the encoding of your xml configuration files. > What's the operating system? > > > -----Original Message----- > > From: gijsbert802 [mailto:vandenbr...@zorgdomein.nl] > > Sent: Saturday, September 12, 2015 8:07 AM > > To: users@activemq.apache.org > > Subject: ActiveMQ exits on startup with UTFDataFormatException: bad > string > > > > Hi all, > > > > I'm trying to upgrade ActiveMQ from 5.11.1 to 5.12, but I'm getting an > error > > when ActiveMQ is starting. It seems to come from the > JDBCPersistenceAdapter. > > We're using an Oracle database as persistent storage. > > > > Other than the ActiveMQ version, nothing changed. > > > > Here's the relevant logging: > > > > 2015-09-12 12:05:45,158 INFO o.a.a.store.jdbc.LeaseDatabaseLocker - > > eda2e5a4c4d0, becoming master with lease expiry Sat Sep 12 12:06:20 UTC > > 2015 on dataSource: JDBC URL = jdbc:oracle:thin:@// > 192.168.99.100:1521/orcl, > > Username = activemq, partitions = 1, max (per partition) = 10, min (per > > partition) = 0, idle max age = 60 min, idle test period = 240 min, > strategy = > > DEFAULT > > 2015-09-12 12:05:45,162 DEBUG o.a.a.s.jdbc.JDBCPersistenceAdapter - > > Cleaning up old messages. > > 2015-09-12 12:05:45,162 DEBUG o.a.a.s.j.adapter.DefaultJDBCAdapter - > > 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=?) ) > > 2015-09-12 12:05:45,170 DEBUG o.a.a.s.j.adapter.DefaultJDBCAdapter - > > Deleted > > 0 old message(s) at priority: 0 > > 2015-09-12 12:05:45,174 DEBUG o.a.a.s.jdbc.JDBCPersistenceAdapter - > Cleanup > > done. > > 2015-09-12 12:05:45,320 ERROR o.a.activemq.broker.BrokerService - Failed > to > > start Apache ActiveMQ ([eda2e5a4c4d0, null], {}) > > java.io.UTFDataFormatException: bad string > > at > > > org.apache.activemq.util.DataByteArrayInputStream.readUTF(DataByteArrayInp > > utStream.java:315) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.v11.BaseDataStreamMarshaller.looseUnmarsha > > lString(BaseDataStreamMarshaller.java:571) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.v11.MessageIdMarshaller.looseUnmarshal(Mes > > sageIdMarshaller.java:122) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.OpenWireFormat.looseUnmarshalNestedObject > > (OpenWireFormat.java:473) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.v11.BaseDataStreamMarshaller.looseUnmarsal > > NestedObject(BaseDataStreamMarshaller.java:466) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.v11.MessageMarshaller.looseUnmarshal(Messa > > geMarshaller.java:220) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.v11.ActiveMQMessageMarshaller.looseUnmars > > hal(ActiveMQMessageMarshaller.java:101) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.v11.ActiveMQObjectMessageMarshaller.looseU > > nmarshal(ActiveMQObjectMessageMarshaller.java:101) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireForm > > at.java:366) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.j > > ava:200) > > ~[activemq-client-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.getLastMessageBroke > > rSequenceId(JDBCPersistenceAdapter.java:266) > > ~[activemq-jdbc-store-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.region.DestinationFactoryImpl.getLastMessageBro > > kerSequenceId(DestinationFactoryImpl.java:147) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.region.RegionBroker.<init>(RegionBroker.java:130) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.broker.jmx.ManagedRegionBroker.<init>(ManagedRegion > > Broker.java:112) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.createRegionBroker(BrokerService.j > > ava:2297) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.createRegionBroker(BrokerService.j > > ava:2290) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.createBroker(BrokerService.java:224 > > 7) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.getBroker(BrokerService.java:981) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.broker.BrokerService.getAdminConnectionContext(Broker > > Service.java:2518) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.startVirtualConsumerDestinations(Br > > okerService.java:2657) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.startDestinations(BrokerService.java > > :2509) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.doStartBroker(BrokerService.java:69 > > 2) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerService.startBroker(BrokerService.java:684) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.broker.BrokerService.start(BrokerService.java:605) > > ~[activemq-broker-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.xbean.XBeanBrokerService.afterPropertiesSet(XBeanBrok > > erService.java:73) > > [activemq-spring-5.12.0.jar:5.12.0] > > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > > ~[na:1.7.0_75] > > at > > > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java: > > 57) > > ~[na:1.7.0_75] > > at > > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI > > mpl.java:43) > > ~[na:1.7.0_75] > > at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75] > > at > > org.springframework.beans.factory.support.AbstractAutowireCapableBeanFact > > ory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1640) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > org.springframework.beans.factory.support.AbstractAutowireCapableBeanFact > > ory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1581) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > org.springframework.beans.factory.support.AbstractAutowireCapableBeanFact > > ory.initializeBean(AbstractAutowireCapableBeanFactory.java:1511) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > org.springframework.beans.factory.support.AbstractAutowireCapableBeanFact > > ory.doCreateBean(AbstractAutowireCapableBeanFactory.java:521) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > org.springframework.beans.factory.support.AbstractAutowireCapableBeanFact > > ory.createBean(AbstractAutowireCapableBeanFactory.java:458) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject( > > AbstractBeanFactory.java:293) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSi > > ngleton(DefaultSingletonBeanRegistry.java:223) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(A > > bstractBeanFactory.java:290) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.springframework.beans.factory.support.AbstractBeanFactory.getBean(Abst > > ractBeanFactory.java:191) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.springframework.beans.factory.support.DefaultListableBeanFactory.preInst > > antiateSingletons(DefaultListableBeanFactory.java:636) > > [spring-beans-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.springframework.context.support.AbstractApplicationContext.finishBeanFa > > ctoryInitialization(AbstractApplicationContext.java:934) > > [spring-context-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.springframework.context.support.AbstractApplicationContext.refresh(Abstr > > actApplicationContext.java:479) > > [spring-context-3.2.11.RELEASE.jar:3.2.11.RELEASE] > > at > > > org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(Resour > > ceXmlApplicationContext.java:64) > > [xbean-spring-3.18.jar:3.18] > > at > > > org.apache.xbean.spring.context.ResourceXmlApplicationContext.<init>(Resour > > ceXmlApplicationContext.java:52) > > [xbean-spring-3.18.jar:3.18] > > at > > > org.apache.activemq.xbean.XBeanBrokerFactory$1.<init>(XBeanBrokerFactory.j > > ava:104) > > [activemq-spring-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.xbean.XBeanBrokerFactory.createApplicationContext(XBe > > anBrokerFactory.java:104) > > [activemq-spring-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.xbean.XBeanBrokerFactory.createBroker(XBeanBrokerFac > > tory.java:67) > > [activemq-spring-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:71 > > ) > > [activemq-broker-5.12.0.jar:5.12.0] > > at > > > org.apache.activemq.broker.BrokerFactory.createBroker(BrokerFactory.java:54 > > ) > > [activemq-broker-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.console.command.StartCommand.runTask(StartCommand > > .java:87) > > [activemq-console-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.console.command.AbstractCommand.execute(AbstractCo > > mmand.java:62) > > [activemq-console-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.console.command.ShellCommand.runTask(ShellCommand > > .java:154) > > [activemq-console-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.console.command.AbstractCommand.execute(AbstractCo > > mmand.java:62) > > [activemq-console-5.12.0.jar:5.12.0] > > at > > org.apache.activemq.console.command.ShellCommand.main(ShellCommand.ja > > va:104) > > [activemq-console-5.12.0.jar:5.12.0] > > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > > ~[na:1.7.0_75] > > at > > > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java: > > 57) > > ~[na:1.7.0_75] > > at > > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorI > > mpl.java:43) > > ~[na:1.7.0_75] > > at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_75] > > at org.apache.activemq.console.Main.runTaskClass(Main.java:262) > > [activemq.jar:5.12.0] > > at org.apache.activemq.console.Main.main(Main.java:115) > > [activemq.jar:5.12.0] > > 2015-09-12 12:05:45,323 INFO o.a.activemq.broker.BrokerService - Apache > > ActiveMQ 5.12.0 (eda2e5a4c4d0, null) is shutting down > > 2015-09-12 12:05:45,324 INFO o.a.a.broker.TransportConnector - Connector > > openwire stopped ... > > > > > > > > -- > > View this message in context: > > http://activemq.2283324.n4.nabble.com/ActiveMQ-exits-on-startup-with- > > UTFDataFormatException-bad-string-tp4701955.html > > Sent from the ActiveMQ - User mailing list archive at Nabble.com. >
