OpenWire v11 was introduced in 5.12.0. Can you try using a 5.11.1 client with a 5.12.0 broker? I'm curious to see if the error still exists if the OpenWire version falls back to v10.
On Sat, Sep 12, 2015 at 11:14 AM, Tim Bain <tb...@alumni.duke.edu> wrote: > 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. > > >
