activemq-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Tim Bain <tb...@alumni.duke.edu>
Subject RE: ActiveMQ exits on startup with UTFDataFormatException: bad string
Date Sat, 12 Sep 2015 15:14:56 GMT
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" <gweatherby@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:vandenbrink@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.
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message