Time Based Retention: Fails to Point Deflector Due To Division by Zero

[packs]

After enabling Time Based retention graylog2-server starts throwing mad errors and requires that I move the configuration back to index count based retention. I'm running a two graylog2-server node cluster and make sure to make the configuration change on both nodes.

The java.lang.ArithmeticException: / by zero error messages continue to fill the logs for as long as the service runs. Changing the retention back to the max_indices model results in the service operating normally.

Component	Version
OS:	Ubuntu Server 14.04.1
Graylog2-Server:	0.92.3-1 (installed from TORCH apt source)
ElasticSearch:	1.3.5

My relevant graylog2-server config items are

elasticsearch_max_time_per_index = 182d
elasticsearch_max_number_of_indices = 200
retention_strategy = delete

The full, redacted, output of /var/log/graylog2-server/server.log

2015-01-14T14:47:47.950Z INFO  [Main] Graylog2 Server up and running.
2015-01-14T14:47:47.964Z INFO  [InputRegistry] Starting [org.graylog2.inputs.XXXXXX] input with ID <XXXXXX>
2015-01-14T14:47:47.966Z INFO  [InputRegistry] Starting [org.graylog2.inputs.XXXXXX] input with ID <XXXXXX>
2015-01-14T14:47:47.967Z INFO  [InputRegistry] Starting [org.graylog2.inputs.XXXXXX] input with ID <XXXXXX>
2015-01-14T14:47:48.005Z INFO  [InputRegistry] Completed starting [org.graylog2.inputs.XXXXXX] input with ID <XXXXXX>
2015-01-14T14:47:48.005Z INFO  [InputRegistry] Completed starting [org.graylog2.inputs.XXXXXX] input with ID <XXXXXX>
2015-01-14T14:47:48.005Z INFO  [InputRegistry] Completed starting [org.graylog2.inputs.XXXXXX] input with ID <XXXXXX>
2015-01-14T14:47:52.092Z ERROR [IndexRotationThread] Couldn't point deflector to a new index
com.google.inject.ProvisionException: Guice provision errors:

1) Error injecting constructor, java.lang.ArithmeticException: / by zero
  at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:43)
  at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.class(TimeBasedRotationStrategy.java:34)
  while locating org.graylog2.indexer.rotation.TimeBasedRotationStrategy
  while locating org.graylog2.plugin.indexer.rotation.RotationStrategy annotated with @com.google.inject.multibindings.Element(setName=,uniqueId=112)
  at org.graylog2.bindings.RotationStrategyBindings.configure(RotationStrategyBindings.java:29)
  while locating java.util.Map<java.lang.String, org.graylog2.plugin.indexer.rotation.RotationStrategy>
    for parameter 0 at org.graylog2.bindings.providers.RotationStrategyProvider.<init>(RotationStrategyProvider.java:32)
  while locating org.graylog2.bindings.providers.RotationStrategyProvider
  while locating org.graylog2.plugin.indexer.rotation.RotationStrategy

1 error
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:987)
    at org.graylog2.periodical.IndexRotationThread.checkForRotation(IndexRotationThread.java:79)
    at org.graylog2.periodical.IndexRotationThread.doRun(IndexRotationThread.java:66)
    at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:83)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ArithmeticException: / by zero
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.determineRotationPeriodAnchor(TimeBasedRotationStrategy.java:100)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:48)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:43)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy$$FastClassByGuice$$de058489.newInstance(<generated>)
    at com.google.inject.internal.cglib.reflect.$FastConstructor.newInstance(FastConstructor.java:40)
    at com.google.inject.internal.DefaultConstructionProxyFactory$1.newInstance(DefaultConstructionProxyFactory.java:60)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
    at com.google.inject.Scopes$1$1.get(Scopes.java:65)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
    at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54)
    at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
    at com.google.inject.spi.ProviderLookup$1.get(ProviderLookup.java:89)
    at com.google.inject.multibindings.MapBinder$RealMapBinder$2.get(MapBinder.java:387)
    at com.google.inject.multibindings.MapBinder$RealMapBinder$2.get(MapBinder.java:383)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
    at com.google.inject.internal.SingleParameterInjector.inject(SingleParameterInjector.java:38)
    at com.google.inject.internal.SingleParameterInjector.getAll(SingleParameterInjector.java:62)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:84)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
    at com.google.inject.internal.BoundProviderFactory.get(BoundProviderFactory.java:53)
    at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
    ... 10 more
2015-01-14T14:47:55.776Z INFO  [Version] HV000001: Hibernate Validator 5.0.0.Final
2015-01-14T14:48:02.003Z ERROR [IndexRotationThread] Couldn't point deflector to a new index
com.google.inject.ProvisionException: Guice provision errors:

1) Error injecting constructor, java.lang.ArithmeticException: / by zero
  at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:43)
  at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.class(TimeBasedRotationStrategy.java:34)
  while locating org.graylog2.indexer.rotation.TimeBasedRotationStrategy
  while locating org.graylog2.plugin.indexer.rotation.RotationStrategy annotated with @com.google.inject.multibindings.Element(setName=,uniqueId=112)
  at org.graylog2.bindings.RotationStrategyBindings.configure(RotationStrategyBindings.java:29)
  while locating java.util.Map<java.lang.String, org.graylog2.plugin.indexer.rotation.RotationStrategy>
    for parameter 0 at org.graylog2.bindings.providers.RotationStrategyProvider.<init>(RotationStrategyProvider.java:32)
  while locating org.graylog2.bindings.providers.RotationStrategyProvider
  while locating org.graylog2.plugin.indexer.rotation.RotationStrategy

1 error
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:987)
    at org.graylog2.periodical.IndexRotationThread.checkForRotation(IndexRotationThread.java:79)
    at org.graylog2.periodical.IndexRotationThread.doRun(IndexRotationThread.java:66)
    at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:83)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ArithmeticException: / by zero
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.determineRotationPeriodAnchor(TimeBasedRotationStrategy.java:100)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:48)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:43)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy$$FastClassByGuice$$de058489.newInstance(<generated>)
    at com.google.inject.internal.cglib.reflect.$FastConstructor.newInstance(FastConstructor.java:40)
    at com.google.inject.internal.DefaultConstructionProxyFactory$1.newInstance(DefaultConstructionProxyFactory.java:60)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
    at com.google.inject.Scopes$1$1.get(Scopes.java:65)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
    at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54)
    at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
    at com.google.inject.spi.ProviderLookup$1.get(ProviderLookup.java:89)
    at com.google.inject.multibindings.MapBinder$RealMapBinder$2.get(MapBinder.java:387)
    at com.google.inject.multibindings.MapBinder$RealMapBinder$2.get(MapBinder.java:383)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
    at com.google.inject.internal.SingleParameterInjector.inject(SingleParameterInjector.java:38)
    at com.google.inject.internal.SingleParameterInjector.getAll(SingleParameterInjector.java:62)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:84)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
    at com.google.inject.internal.BoundProviderFactory.get(BoundProviderFactory.java:53)
    at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
    ... 10 more
2015-01-14T14:48:04.714Z ERROR [MasterCacheWorkerThread] Error while trying to work on MasterCache <org.graylog2.caches.DiskJournalCache.Input>.
java.lang.NullPointerException
    at org.mapdb.Queues$SimpleQueue.peek(Queues.java:117)
    at org.mapdb.Queues$SimpleQueue.isEmpty(Queues.java:287)
    at org.graylog2.caches.DiskJournalCache.isEmpty(DiskJournalCache.java:242)
    at org.graylog2.periodical.MasterCacheWorkerThread.work(MasterCacheWorkerThread.java:106)
    at org.graylog2.periodical.MasterCacheWorkerThread.access$200(MasterCacheWorkerThread.java:43)
    at org.graylog2.periodical.MasterCacheWorkerThread$1.run(MasterCacheWorkerThread.java:80)
    at java.lang.Thread.run(Thread.java:745)
2015-01-14T14:48:11.969Z ERROR [IndexRotationThread] Couldn't point deflector to a new index
com.google.inject.ProvisionException: Guice provision errors:

1) Error injecting constructor, java.lang.ArithmeticException: / by zero
  at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:43)
  at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.class(TimeBasedRotationStrategy.java:34)
  while locating org.graylog2.indexer.rotation.TimeBasedRotationStrategy
  while locating org.graylog2.plugin.indexer.rotation.RotationStrategy annotated with @com.google.inject.multibindings.Element(setName=,uniqueId=112)
  at org.graylog2.bindings.RotationStrategyBindings.configure(RotationStrategyBindings.java:29)
  while locating java.util.Map<java.lang.String, org.graylog2.plugin.indexer.rotation.RotationStrategy>
    for parameter 0 at org.graylog2.bindings.providers.RotationStrategyProvider.<init>(RotationStrategyProvider.java:32)
  while locating org.graylog2.bindings.providers.RotationStrategyProvider
  while locating org.graylog2.plugin.indexer.rotation.RotationStrategy

1 error
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:987)
    at org.graylog2.periodical.IndexRotationThread.checkForRotation(IndexRotationThread.java:79)
    at org.graylog2.periodical.IndexRotationThread.doRun(IndexRotationThread.java:66)
    at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:83)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ArithmeticException: / by zero
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.determineRotationPeriodAnchor(TimeBasedRotationStrategy.java:100)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:48)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy.<init>(TimeBasedRotationStrategy.java:43)
    at org.graylog2.indexer.rotation.TimeBasedRotationStrategy$$FastClassByGuice$$de058489.newInstance(<generated>)
    at com.google.inject.internal.cglib.reflect.$FastConstructor.newInstance(FastConstructor.java:40)
    at com.google.inject.internal.DefaultConstructionProxyFactory$1.newInstance(DefaultConstructionProxyFactory.java:60)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:85)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter$1.call(ProviderToInternalFactoryAdapter.java:46)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
    at com.google.inject.internal.ProviderToInternalFactoryAdapter.get(ProviderToInternalFactoryAdapter.java:40)
    at com.google.inject.Scopes$1$1.get(Scopes.java:65)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
    at com.google.inject.internal.FactoryProxy.get(FactoryProxy.java:54)
    at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1031)
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
    at com.google.inject.spi.ProviderLookup$1.get(ProviderLookup.java:89)
    at com.google.inject.multibindings.MapBinder$RealMapBinder$2.get(MapBinder.java:387)
    at com.google.inject.multibindings.MapBinder$RealMapBinder$2.get(MapBinder.java:383)
    at com.google.inject.internal.InternalFactoryToProviderAdapter.get(InternalFactoryToProviderAdapter.java:40)
    at com.google.inject.internal.SingleParameterInjector.inject(SingleParameterInjector.java:38)
    at com.google.inject.internal.SingleParameterInjector.getAll(SingleParameterInjector.java:62)
    at com.google.inject.internal.ConstructorInjector.construct(ConstructorInjector.java:84)
    at com.google.inject.internal.ConstructorBindingImpl$Factory.get(ConstructorBindingImpl.java:254)
    at com.google.inject.internal.BoundProviderFactory.get(BoundProviderFactory.java:53)
    at com.google.inject.internal.InjectorImpl$4$1.call(InjectorImpl.java:978)
    at com.google.inject.internal.InjectorImpl.callInContext(InjectorImpl.java:1024)
    at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:974)
    ... 10 more

[kroepke]

Hi!

This was previously fixed in #836 but hasn't been backported to 0.92, not even to the 0.92.4 that's being released right now.
It is fixed in 1.0 beta, however.
A workaround is to pick a slightly different time period that does not have a zero value for its component, but that is tricky.
Probably the best bet is to stick with count based retention for now until 1.0 is out.
Sorry for the inconvenience.

[joschi]

I've pulled the fix into the 0.92 branch (commit 2f27895).

[packs]

Does your advice to select a time period that does not include a zero apply to both elasticsearch_max_time_per_index and elasticsearch_max_number_of_indices? Since I'm using 182 days I wouldn't expect that to have a zero component, unless the no-zero bug applies in a stranger way than I thought.

[kroepke]

It is stranger than you think. It tries to find an anchor time, based on
the largest stride in time.

For example 1h would anchor on the last full hour, not on the time you
started the server.
The new version might fail to find one but won't divide by zero anymore.
On Jan 14, 2015 6:40 PM, "Scott Pack" notifications@github.com wrote:

Does your advice to select a time period that does not include a zero
apply to both elasticsearch_max_time_per_index and
elasticsearch_max_number_of_indices? Since I'm using 182 days I wouldn't
expect that to have a zero component, unless the no-zero bug applies in a
stranger way than I thought.

—
Reply to this email directly or view it on GitHub
#871 (comment)
.