IndexOutOfBoundsException under 0.3.3

[michael...@imagini.net]

Just upgraded to 0.3.3 and I saw the following in the logs just after starting up. Is this normal or a cause for concern?

(Thanks for the answers quick release)

Michael

2014-08-05 10:15:51,024 ERROR [scoring-service-akka.actor.default-dispatcher-9] akka.actor.OneForOneStrategy - index 7040
java.lang.IndexOutOfBoundsException: index 7040
at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)
at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:34)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:295)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:372)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)
at kamon.metric.instrument.PaddedMinMaxCounter.refreshValues(MinMaxCounter.scala:110)
at kamon.metric.instrument.PaddedMinMaxCounter.collect(MinMaxCounter.scala:89)
at kamon.metric.instrument.PaddedMinMaxCounter.collect(MinMaxCounter.scala:65)
at kamon.metric.ActorMetrics$ActorMetricsRecorder.collect(ActorMetrics.scala:42)
at kamon.metric.ActorMetrics$ActorMetricsRecorder.collect(ActorMetrics.scala:35)
at kamon.metric.Subscriptions$$anonfun$collectAll$1.apply(Subscriptions.scala:83)
at kamon.metric.Subscriptions$$anonfun$collectAll$1.apply(Subscriptions.scala:82)
at scala.collection.Iterator$class.foreach(Iterator.scala:743)
at scala.collection.concurrent.TrieMapIterator.foreach(TrieMap.scala:923)
at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
at scala.collection.concurrent.TrieMap.foreach(TrieMap.scala:633)
at kamon.metric.Subscriptions.collectAll(Subscriptions.scala:82)
at kamon.metric.Subscriptions.flush(Subscriptions.scala:69)
at kamon.metric.Subscriptions$$anonfun$receive$1.applyOrElse(Subscriptions.scala:41)
at akka.actor.Actor$class.aroundReceive(Actor.scala:465)
at kamon.metric.Subscriptions.aroundReceive(Subscriptions.scala:27)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:516)
at akka.actor.ActorCell.invoke_aroundBody0(ActorCell.scala:487)
at akka.actor.ActorCell$AjcClosure1.run(ActorCell.scala:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at akka.instrumentation.ActorCellInstrumentation$$anonfun$aroundBehaviourInvoke$1.apply(ActorCellInstrumentation.scala:56)
at kamon.trace.TraceRecorder$.withTraceContext(TraceRecorder.scala:69)
at akka.instrumentation.ActorCellInstrumentation.aroundBehaviourInvoke(ActorCellInstrumentation.scala:55)
at akka.actor.ActorCell.invoke(ActorCell.scala:483)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:238)
at akka.dispatch.Mailbox.run(Mailbox.scala:220)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:393)
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)

[Ivan Topolnjak]

Michael,

Thanks for reporting this issue and trying out 0.3.3 right away! That error happens when a value that is lower than zero or greater than the highest trackable value is written to a histogram like the one backing the mailbox size observations.. We already have some code to protect us from that issue and I'm not sure of why it failed this time.. Does it always fail when starting your app? Is it reproducible? any info that can help us reproduce it would be greatly appreciated.

Also, just to give you a little background on why we did that: for monitoring mailboxes we have this thing called a MinMaxCounter, which internally has 3 structures tracking the min, max and current value of the mailbox.. In a fixed interval we read those three values and store them in a histogram that will eventually be flushed to all registered reporters. Our instrumentation increments by one after a message has been successfully queued in mailbox and decrements by one when a message is dequeued from the mailbox... this sounds like it should never fall bellow zero, but it turns out that akka internally schedules the actor for execution when the message is queued in the mailbox and with some lucky (or unlucky if you like it better) timings the message will be dequeued for processing by another thread before the call to `sendMessage` in the ActorCell completes, making the mailbox size fall to -1 and quickly get back to 0. For a MinMaxCounter, if the values fall bellow zero we assume them to be zero and there (in theory) is no chance that a value bellow zero is recorded.. I'll investigate more on this and try to reproduce it somehow, will keep you posted, best regards!

[Ivan Topolnjak]

oh and I'm also assuming that you didn't have more than 1 billion messages in the mailbox, didn't you? :)

[michael...@imagini.net]

It fails repeatedly on multiple machines, not just on startup but regularly as the code runs, and the index is always 7040.

I'm not doing anything with actors "manually" - just a spray app so creating one HttpServiceActor and sending a Http.Bind to start the server. Anything else will be spray internals. I don't collect the reply so there's at least one message to dead.letters. The only other slightly weird thing I can think of about my code is that I sometimes call TraceRecorder.finish() without a trace present (which gives a warning), because I have some code that can be called either from spray code or from other code in which I manually start a transaction.

[Ivan Topolnjak]

Michael,

I just pushed version 0.3.4-5e29348abfaac542ef30bf9b6fc9dc13d69e1c22 to our snapshots repo [1], it will print out a bit of info about the values being recorded when it fails, can you please run your app with that version and tell me what the output is?, thanks in advance for your collaboration!

[1] http://snapshots.kamon.io

[michael...@imagini.net]

I can't see anything newer than 0.3.3-a304fbb8d30f16923ab4d6b03c47b9a95f7f3529 under e.g. http://snapshots.kamon.io/io/kamon/kamon-core_2.11/ ?

[Ivan Topolnjak]

Sorry, I published for Scala 2.10, the version for Scala 2.11 is 0.3.4-5929a6472edb0a8d3af1d8661ee0d30d3163b880.

[michael...@imagini.net]

I only see the one extra log line, is this what you wanted?

Storage of min [-9223372036854775808] is about to fail, current=0, maxTrackableValue=999999999, significantDigits=2
2014-08-06 09:27:30,668 ERROR [scoring-service-akka.actor.default-dispatcher-14] akka.actor.OneForOneStrategy - index 7040

java.lang.IndexOutOfBoundsException: index 7040
at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)
at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:34)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:295)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:372)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)

at kamon.metric.instrument.PaddedMinMaxCounter.refreshValues(MinMaxCounter.scala:114)

[mohnish...@gmail.com]

I encounter this problem as well, during app startup and for me also the index is always 7040 with the following stack
[ERROR] [08/07/2014 11:16:00.844] [xyz-akka.actor.default-dispatcher-31] [akka://xyz/user/kamon-metrics-subscriptions] index 7040

java.lang.IndexOutOfBoundsException: index 7040
at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)

at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:36)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:285)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:216)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)
at kamon.metric.instrument.PaddedMinMaxCounter.refreshValues(MinMaxCounter.scala:111)

at kamon.metric.instrument.PaddedMinMaxCounter.collect(MinMaxCounter.scala:89)
at kamon.metric.instrument.PaddedMinMaxCounter.collect(MinMaxCounter.scala:65)
at kamon.metric.ActorMetrics$ActorMetricsRecorder.collect(ActorMetrics.scala:42)
at kamon.metric.ActorMetrics$ActorMetricsRecorder.collect(ActorMetrics.scala:35)
at kamon.metric.Subscriptions$$anonfun$collectAll$1.apply(Subscriptions.scala:83)
at kamon.metric.Subscriptions$$anonfun$collectAll$1.apply(Subscriptions.scala:82)

at scala.collection.Iterator$class.foreach(Iterator.scala:727)
at scala.collection.concurrent.TrieMapIterator.foreach(TrieMap.scala:922)
at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
at scala.collection.concurrent.TrieMap.foreach(TrieMap.scala:632)

at kamon.metric.Subscriptions.collectAll(Subscriptions.scala:82)
at kamon.metric.Subscriptions.flush(Subscriptions.scala:69)
at kamon.metric.Subscriptions$$anonfun$receive$1.applyOrElse(Subscriptions.scala:41)
at akka.actor.Actor$class.aroundReceive(Actor.scala:465)
at kamon.metric.Subscriptions.aroundReceive(Subscriptions.scala:27)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:516)
at akka.actor.ActorCell.invoke_aroundBody0(ActorCell.scala:487)
at akka.actor.ActorCell$AjcClosure1.run(ActorCell.scala:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at akka.instrumentation.ActorCellInstrumentation$$anonfun$aroundBehaviourInvoke$1.apply(ActorCellInstrumentation.scala:56)
at kamon.trace.TraceRecorder$.withTraceContext(TraceRecorder.scala:69)
at akka.instrumentation.ActorCellInstrumentation.aroundBehaviourInvoke(ActorCellInstrumentation.scala:55)
at akka.actor.ActorCell.invoke(ActorCell.scala:483)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:238)
at akka.dispatch.Mailbox.run(Mailbox.scala:220)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:393)
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)

[mohnish...@gmail.com]

Just used the new snapshot jars for scala 2.10 and here is some more info. Could we also print the name of the metric for which this value is being generated.

Storing of [-9223372036854775808] will fail, current=0, highestTrackableValue=999999999
[ERROR] [08/07/2014 11:32:49.746] [xyz-akka.actor.default-dispatcher-26] [akka://xyz/user/kamon-metrics-subscriptions] index 7040

java.lang.IndexOutOfBoundsException: index 7040
at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)
at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:36)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:285)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:216)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)

at kamon.metric.instrument.PaddedMinMaxCounter.refreshValues(MinMaxCounter.scala:113)

Storing of [-9223372036854775808] will fail, current=0, highestTrackableValue=999999999
[ERROR] [08/07/2014 11:32:49.780] [FireFly-akka.actor.default-dispatcher-34] [akka://FireFly/user/kamon-metrics-subscriptions] index 7040

java.lang.IndexOutOfBoundsException: index 7040
at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)
at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:36)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:285)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:216)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)

at kamon.metric.instrument.PaddedMinMaxCounter.refreshValues(MinMaxCounter.scala:113)

[Diego Parra]

I just pushed version 0.3.4-cc26f291af439812954139f1f4efc84e9ed4c1fd to our snapshots repo [1], it will resolve the issue.

you can please run your app with that version and tell me what the output is?, thanks in advance for your collaboration!

[1] http://snapshots.kamon.io

--
You received this message because you are subscribed to the Google Groups "kamon-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to kamon-user+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[michael...@imagini.net]

Trying to build against 0.3.4-cc26f291af439812954139f1f4efc84e9ed4c1fd I get "error: error while loading TraceRecorder, invalid LOC header (bad signature)".

[Diego Parra]

can you try with this version 0.3.4-cc26f291af439812954139f1f4efc84e9ed4c1fd is for scala 2.11

thanks.

[michael...@imagini.net]

0.3.4-cc26f291af439812954139f1f4efc84e9ed4c1fd is the version I got that error with. Did you mean to say some other version?

[Diego Parra]

Sorry 0.3.4-841c2e941301dfb74b667206c073271a266dce0f

[michael...@imagini.net]

Ok, running with that version as far as I can see the error has stopped?

[Mohnish Kodnani]

Can you tell me a version to use for 2.10 so I can also verify at my end if the error goes away ?

You received this message because you are subscribed to a topic in the Google Groups "kamon-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/kamon-user/ph568abmR0s/unsubscribe.
To unsubscribe from this group and all its topics, send an email to kamon-user+...@googlegroups.com.

[Diego Parra]

Hi Mohnish,

sorry for the delay, you can try with 0.3.4-282e866034010856c2f358125b4fa7264626304e for scala 2.10, this fix we will include in the next release and again thanks for your collaboration!

Diego

[michael...@imagini.net]

Hmm, I've now seen the error on a system that should be running with that version:

2014-08-11 14:07:10,870 ERROR [scoring-service-akka.actor.default-dispatcher-7] akka.actor.OneForOneStrategy - index 7040

java.lang.IndexOutOfBoundsException: index 7040
at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)
at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:34)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:295)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:372)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)

at kamon.metric.instrument.PaddedMinMaxCounter.refreshValues(MinMaxCounter.scala:111)
at kamon.metric.instrument.PaddedMinMaxCounter.collect(MinMaxCounter.scala:89)
at kamon.metric.instrument.PaddedMinMaxCounter.collect(MinMaxCounter.scala:65)
at kamon.metric.ActorMetrics$ActorMetricsRecorder.collect(ActorMetrics.scala:42)
at kamon.metric.ActorMetrics$ActorMetricsRecorder.collect(ActorMetrics.scala:35)
at kamon.metric.Subscriptions$$anonfun$collectAll$1.apply(Subscriptions.scala:83)
at kamon.metric.Subscriptions$$anonfun$collectAll$1.apply(Subscriptions.scala:82)

at scala.collection.Iterator$class.foreach(Iterator.scala:743)
at scala.collection.concurrent.TrieMapIterator.foreach(TrieMap.scala:923)
at scala.collection.IterableLike$class.foreach(IterableLike.scala:72)
at scala.collection.concurrent.TrieMap.foreach(TrieMap.scala:633)
at kamon.metric.Subscriptions.collectAll(Subscriptions.scala:82)
at kamon.metric.Subscriptions.flush(Subscriptions.scala:69)
at kamon.metric.Subscriptions$$anonfun$receive$1.applyOrElse(Subscriptions.scala:41)
at akka.actor.Actor$class.aroundReceive(Actor.scala:465)
at kamon.metric.Subscriptions.aroundReceive(Subscriptions.scala:27)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:516)
at akka.actor.ActorCell.invoke_aroundBody0(ActorCell.scala:487)
at akka.actor.ActorCell$AjcClosure1.run(ActorCell.scala:1)
at org.aspectj.runtime.reflect.JoinPointImpl.proceed(JoinPointImpl.java:149)
at akka.instrumentation.ActorCellInstrumentation$$anonfun$aroundBehaviourInvoke$1.apply(ActorCellInstrumentation.scala:56)
at kamon.trace.TraceRecorder$.withTraceContext(TraceRecorder.scala:69)
at akka.instrumentation.ActorCellInstrumentation.aroundBehaviourInvoke(ActorCellInstrumentation.scala:55)
at akka.actor.ActorCell.invoke(ActorCell.scala:483)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:238)
at akka.dispatch.Mailbox.run(Mailbox.scala:220)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:393)
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)

No relevant messages around it that I can see (I assume you removed the "about to fail..." message?)

[Mohnish Kodnani]

Hi Diego, 

The 2.10 library that you provided seems to have resolved the stack trace that occurred at application startup. 

I no longer see that stack. 

When is the next release planned ?

Thanks

mohnis

You received this message because you are subscribed to a topic in the Google Groups "kamon-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/kamon-user/ph568abmR0s/unsubscribe.
To unsubscribe from this group and all its topics, send an email to kamon-user+...@googlegroups.com.

[Ivan Topolnjak]

Guys,

the next release is at least 3 weeks away from now, we hope that you can rely on the snapshots until we get there... we still need to investigate more this issue, since what currently is being made is just a patch that alleviates the symptom (a exception being thrown) but leaves the bug there (for some weird reason, trying to record Long.MinValue).. I'm taking the task of verifying this nos and will keep you posted, thanks a lot for helping us make Kamon better!

[Ivan Topolnjak]

Thanks a lot for bringing up this issue, as of [d2a2d5] this bug has been definitely solved! The following snapshots have been pushed:

  - for Scala 2.10: 0.3.4-d2a2d590abf0f287d5d07edc00970f4c6069d20e

  - for Scala 2.11: 0.3.4-207034dd531687b28819980bb61831576ef5a3ea

We are aware that this bug makes the Kamon versions currently available unstable and not usable in production so it would be nice if you guys can test these snapshots on your dev environments and reconfirm that the bug is gone so we can release a truly stable version to all of our users, looking forward to your feedback!

[d2a2d5] https://github.com/kamon-io/Kamon/commit/d2a2d590abf0f287d5d07edc00970f4c6069d20e

[adam...@gmail.com]

Hi,

I can confirm that this issue no longer appears in my application with the 2.11 snapshot.

[Diego Parra]

thanks adam for you feedback!!!

[Mohnish Kodnani]

Works for me for 2.10.

--
You received this message because you are subscribed to a topic in the Google Groups "kamon-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/kamon-user/ph568abmR0s/unsubscribe.
To unsubscribe from this group and all its topics, send an email to kamon-user+...@googlegroups.com.

[michael...@imagini.net]

I'm still seeing the error under 207034dd531687b28819980bb61831576ef5a3ea . Will update to 0.3.4 today and see if that makes any difference.

[Ivan Topolnjak]

Are you entirely sure that you were running the latest Kamon snapshot when the issue was reproduced? I found a way to reproduce the problem and testing many times against 2.10 and 2.11 branches before releasing.. let us know what you find, thanks!

[אדם חונן‎]

One of the things that almost confused me was that initially I still had the 0.3.3 jars left behind which caused the new ones to be disregarded due to classpath precedence. Luckily the stacktrace easily clarifies this.

בתאריך 14 באוג 2014 18:07, "Ivan Topolnjak" <ivan...@gmail.com> כתב:

Are you entirely sure that you were running the latest Kamon snapshot when the issue was reproduced? I found a way to reproduce the problem and testing many times against 2.10 and 2.11 branches before releasing.. let us know what you find, thanks!

--

[michael...@imagini.net]

No failures under 0.3.4 so far.

[Ivan Topolnjak]

Excellent, thanks for sharing!

[elmar...@cupenya.com]

Hello, I'm getting this error under 0.3.4 as well. It seems reproducible after running under full load for around 2 hours (about a hundred million of messages across 20 actors).

Is there something I can do to help debug this?

[ERROR] [08/28/2014 06:59:59.772] [cpy-engine-akka.actor.default-dispatcher-13] [ActorSystem(cpy-engine)] Uncaught error from thread [cpy-engine-akka.actor.default-dispatcher-13]
java.lang.IndexOutOfBoundsException: index 4963

at java.util.concurrent.atomic.AtomicLongArray.checkedByteOffset(AtomicLongArray.java:64)
at java.util.concurrent.atomic.AtomicLongArray.addAndGet(AtomicLongArray.java:256)
at java.util.concurrent.atomic.AtomicLongArray.incrementAndGet(AtomicLongArray.java:235)
at org.HdrHistogram.AtomicHistogram.incrementCountAtIndex(AtomicHistogram.java:34)
at org.HdrHistogram.AbstractHistogram.recordSingleValue(AbstractHistogram.java:295)
at org.HdrHistogram.AbstractHistogram.recordValue(AbstractHistogram.java:372)
at kamon.metric.instrument.HdrHistogram.record(Histogram.scala:105)

at akka.instrumentation.ActorCellInstrumentation$$anonfun$aroundBehaviourInvoke$1.apply(ActorCellInstrumentation.scala:62)
at akka.instrumentation.ActorCellInstrumentation$$anonfun$aroundBehaviourInvoke$1.apply(ActorCellInstrumentation.scala:60)
at scala.Option.map(Option.scala:145)
at akka.instrumentation.ActorCellInstrumentation.aroundBehaviourInvoke(ActorCellInstrumentation.scala:59)

[Ivan Topolnjak]

Hello Elmar,

Welcome and thanks for trying out Kamon! Judging by the stacktrace and the index number this is a totally different issue.. it seems like a message was in the mailbox of an actor for way more than one hour which is the default limit [1] for HDR histogram tracking the time-in-mailbox metric, making it fall out of bounds when trying to store that metric.. does that sound reasonable to you? If that's the case, please feel free to move up the limits in the corresponding settings, all limits are expressed in nanoseconds, except for the mailbox size which has the actual limit. Let us know if this helps, best regards!

[1] https://github.com/kamon-io/Kamon/blob/master/kamon-core/src/main/resources/reference.conf#L87

[Elmar Weber]

Hi Ivan,

sorry, took a while. Thanks for your quick reply. Yes, that sounds like a possible source of the problem. Some queues can become quite large with requests and take some time until they are fully processed. I'll increase the value and run it again.

Cheers,
Elmar

[Elmar Weber]

Hi Ivan,

I tried to overwrite the settings by tripling the value, but the problem persists.

kamon.metrics.precision.default-histogram-precision.highest-trackable-value=10800000000000

The first index that is declared as out of bounds is 4608 after about 1.5h, so long before the 3 hours as defined by the new value.
Is this correct, or did I get the wrong setting?

Cheers,
Elmar


On Friday, August 29, 2014 12:40:37 AM UTC+2, Ivan Topolnjak wrote:

[Ivan Topolnjak]

Hello Elmar, sorry for the late response! I did a couple tests and the problem I found was the way in which you are overwriting the configuration setting: it turns out that all substitution inside reference.conf files are resolved first, before merging everything else.. if the substitution were in a application.conf file it would work exactly as you think it would. I found a issue in the typesafe-config repo [1] that talks about this and also references a workaround for this. I think it would be rather easier to just overwrite the relevant key in your application.conf, something like:

kamon.metrics.precision.actor.time-in-mailbox.highest-trackable-value=10800000000000

That should solve your issue, let us know how it goes, best regards!

[1] https://github.com/typesafehub/config/issues/51

[Elmar Weber]

Hi Ivan,

I tried that too, same result, my application conf now overwrites the following settings:

kamon.metrics.precision.default-histogram-precision.highest-trackable-value=10800000000000
kamon.metrics.precision.actor.time-in-mailbox.highest-trackable-value=10800000000000

They are definitely picked up by the system, I double checked, we are dumping the typesafe config on app start anyway for debug purposes, there the settings are overwritten and applied.

Any other ideas I can check up on?

Thank you,
Elmar

[Ivan Topolnjak]

Elmar, are you entirely sure that the configuration setting is present in the config object being used by the actor system? I double checked today to be entirely sure that it is picking up the config from

  kamon.metrics.precision.actor.time-in-mailbox.highest-trackable-value=10800000000000

and it certainly does, can you describe a bit more of how are you using the typesafe config library? maybe you are doing some custom stuff that might be leaving this out of where we need it.

[Elmar Weber]

Hi Ivan,

we are deploying to tomcat with a reference.conf in the war file and then overwrite it with an application.conf in tomcats environment path. So all final settings are coming from there. The settings from above I put into the application.conf since I can change this without doing a new build.

I know the settings are picked up because we are doing a dump of the whole config on startup, and there the mailbox.highest trackable value is at 108..... So I assume that your ConfigFactory gets the same values. Is there a debug level or something I can active to check if that is the case? I could not find a relevant logging statement in the configuration or instrumentation code. If you think it helps I can also walk through this via a remote session.

Thanks,
Elmar

[Ivan Topolnjak]

Hello Elmar,

I know the settings are picked up because we are doing a dump of the whole config on startup, and there the mailbox.highest trackable value is at 108..... So I assume that your ConfigFactory gets the same values.

Well, we don't use the ConfigFactory to obtain a Config instance but rather use the one that the ActorSystem has.. Kamon works as a extension to a ActorSystem and we get everything we need from the configuration already available to that ActorSystem.. maybe you have more than one ActorSystem and the settings are not going to the one you need them to go?

If you think it helps I can also walk through this via a remote session.

Sure, add me on google hangouts and ping me!