Bug 989698 - Exception while writing to hornetq
Exception while writing to hornetq
Status: CLOSED CURRENTRELEASE
Product: Candlepin
Classification: Community
Component: candlepin (Show other bugs)
0.9
Unspecified Unspecified
high Severity low
: ---
: ---
Assigned To: Devan Goodwin
Katello QA List
:
Depends On:
Blocks: rhsm-rhel510
  Show dependency treegraph
 
Reported: 2013-07-29 14:17 EDT by Dennis Crissman
Modified: 2015-05-14 10:52 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-10-01 10:12:29 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Dennis Crissman 2013-07-29 14:17:20 EDT
I have started getting this exception. It does not appear to effect functionality, but would like someone to take a look.

Jul 29, 2013 5:58:29 PM org.hornetq.core.logging.impl.JULLogDelegate warn
WARNING: Sending unexpected exception to the client
java.lang.IllegalStateException: Can't write records bigger than the bufferSize(10240) on the journal
	at org.hornetq.core.journal.impl.TimedBuffer.checkSize(TimedBuffer.java:212)
	at org.hornetq.core.journal.impl.AbstractSequentialFile.fits(AbstractSequentialFile.java:192)
	at org.hornetq.core.journal.impl.JournalImpl.appendRecord(JournalImpl.java:2911)
	at org.hornetq.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:839)
	at org.hornetq.core.persistence.impl.journal.JournalStorageManager.storeMessage(JournalStorageManager.java:552)
	at org.hornetq.core.postoffice.impl.PostOfficeImpl.processRoute(PostOfficeImpl.java:1021)
	at org.hornetq.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:679)
	at org.hornetq.core.postoffice.impl.PostOfficeImpl.route(PostOfficeImpl.java:581)
	at org.hornetq.core.server.impl.ServerSessionImpl.doSend(ServerSessionImpl.java:1437)
	at org.hornetq.core.server.impl.ServerSessionImpl.send(ServerSessionImpl.java:1164)
	at org.hornetq.core.protocol.core.ServerSessionPacketHandler.handlePacket(ServerSessionPacketHandler.java:441)
	at org.hornetq.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:508)
	at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:556)
	at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:517)
	at org.hornetq.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:534)
	at org.hornetq.core.remoting.impl.invm.InVMConnection$1.run(InVMConnection.java:169)
	at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:100)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:679)
Jul 29 17:58:29 [ITClusteredScheduler_Worker-5] ERROR org.candlepin.audit.EventSinkImpl - Error while trying to send event: Event [id=null, target=POOL, type=CREATED, time=Mon Jul 29 17:58:29 EDT 2013, entity=8a878dab402c678201402c70900c00f1]
HornetQException[errorCode=0 message=null]
	at org.hornetq.core.protocol.core.impl.ChannelImpl.sendBlocking(ChannelImpl.java:312)
	at org.hornetq.core.client.impl.ClientProducerImpl.doSend(ClientProducerImpl.java:287)
	at org.hornetq.core.client.impl.ClientProducerImpl.send(ClientProducerImpl.java:135)
	at org.candlepin.audit.EventSinkImpl.sendEvent(EventSinkImpl.java:88)
	at org.candlepin.audit.EventSinkImpl.emitPoolCreated(EventSinkImpl.java:112)
	at org.candlepin.controller.CandlepinPoolManager.createPool(CandlepinPoolManager.java:308)
	at org.candlepin.controller.CandlepinPoolManager.createPoolsForSubscription(CandlepinPoolManager.java:295)
	at org.candlepin.controller.CandlepinPoolManager.refreshPoolsWithoutRegeneration(CandlepinPoolManager.java:159)
	at org.candlepin.controller.Refresher.run(Refresher.java:93)
	at org.candlepin.pinsetter.tasks.RefreshPoolsJob.execute(RefreshPoolsJob.java:71)
	at org.candlepin.pinsetter.tasks.RefreshPoolsJob$$EnhancerByGuice$$c77d574d.CGLIB$execute$0(<generated>)
	at org.candlepin.pinsetter.tasks.RefreshPoolsJob$$EnhancerByGuice$$c77d574d$$FastClassByGuice$$ea5a6d7e.invoke(<generated>)
	at com.google.inject.internal.cglib.proxy.$MethodProxy.invokeSuper(MethodProxy.java:228)
	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
	at com.google.inject.persist.jpa.JpaLocalTxnInterceptor.invoke(JpaLocalTxnInterceptor.java:66)
	at com.google.inject.internal.InterceptorStackCallback$InterceptedMethodInvocation.proceed(InterceptorStackCallback.java:72)
	at com.google.inject.internal.InterceptorStackCallback.intercept(InterceptorStackCallback.java:52)
	at org.candlepin.pinsetter.tasks.RefreshPoolsJob$$EnhancerByGuice$$c77d574d.execute(<generated>)
	at org.candlepin.pinsetter.core.TransactionalPinsetterJob.execute(TransactionalPinsetterJob.java:50)
	at org.quartz.core.JobRunShell.run(Unknown Source)
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(Unknown Source)
Comment 1 Dennis Crissman 2013-07-29 14:19:15 EDT
I am using the following ids in stage.

OWNER_KEY=711497
PRODUCT_KEY=RH1149049
SUBSCRIPTION_KEY=2252576
Comment 3 Dennis Crissman 2013-07-29 14:50:19 EDT
I just learned that this is causing problems in our qa environment because it is logging as an error and is filling up the log files.

Raising priority a notch.

Thanks.
Comment 4 Devan Goodwin 2013-08-02 15:08:52 EDT
I think I have a fix for this, it is not 100% certain however as I was unable to reproduce with current code locally (which is odd), but by making some changes I was able to get a similar exception and I think I can see why the problem occurred.

I believe problem results from 5ab37031d82349caa78f6bf2af5cda1b17334d59 where we added the ability to configure the "min large message size" for hornetq, a threshold after which it will start to break the message up and send in chunks.

However in this commit, you'll see we're using the same value for both the min large message size, and the journal buffer size. This appears incorrect as the min large message size should always be smaller than the journal buffer size.

The default journal buffer size is supposedly 490kb. By removing the setting of this explicitly in our code, and bumping the min large message size up to something larger than that, I was able to see this:

Aug 02, 2013 3:42:23 PM org.hornetq.core.logging.impl.JULLogDelegate warn
WARNING: Sending unexpected exception to the client
java.lang.IllegalStateException: Can't write records bigger than the bufferSize(501760) on the journal
        at org.hornetq.core.journal.impl.TimedBuffer.checkSize(TimedBuffer.java:212)
        at org.hornetq.core.journal.impl.AbstractSequentialFile.fits(AbstractSequentialFile.java:188)
        at org.hornetq.core.journal.impl.JournalImpl.appendRecord(JournalImpl.java:2911)
        at org.hornetq.core.journal.impl.JournalImpl.appendAddRecord(JournalImpl.java:839)

However with code that is using the same value for min message size, and the journal buffer size, I can't make the exception happen locally as it does in stage.
Comment 5 Devan Goodwin 2013-08-06 12:06:23 EDT
Fixed in candlepin.git master: cdea261329a8682b840cf0c4a1dbccb2a95ea1fa

Will appear in 0.8.20.
Comment 6 Bryan Kearney 2013-10-01 10:12:29 EDT
Released with 5.10

Note You need to log in before you can comment on or make changes to this bug.