NullPointerException encountered during indices housekeeping

[davidktw]

NullPointerException encountered during indices housekeeping

Expected Behavior

Indices should be housekeep to only retain the number of configured retention logs number

Current Behavior

Old indices are not removed.

2017-02-14T09:35:35.802Z ERROR [IndexRetentionThread] Uncaught exception in periodical
java.lang.NullPointerException: null
        at org.graylog2.indexer.retention.strategies.AbstractIndexCountBasedRetentionStrategy.lambda$runRetention$2(AbstractIndexCountBasedRetentionStrategy.java:88) ~[graylog.jar:?]
        at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:174) ~[?:1.8.0_121]
        at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:175) ~[?:1.8.0_121]
        at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948) ~[?:1.8.0_121]
        at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481) ~[?:1.8.0_121]
        at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471) ~[?:1.8.0_121]
        at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708) ~[?:1.8.0_121]
        at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:1.8.0_121]
        at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499) ~[?:1.8.0_121]
        at org.graylog2.indexer.retention.strategies.AbstractIndexCountBasedRetentionStrategy.runRetention(AbstractIndexCountBasedRetentionStrategy.java:90) ~[graylog.jar:?]
        at org.graylog2.indexer.retention.strategies.AbstractIndexCountBasedRetentionStrategy.retain(AbstractIndexCountBasedRetentionStrategy.java:82) ~[graylog.jar:?]
        at org.graylog2.periodical.IndexRetentionThread.doRun(IndexRetentionThread.java:85) ~[graylog.jar:?]
        at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:77) [graylog.jar:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_121]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_121]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_121]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_121]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121]

Possible Solution

diff -dBb AbstractIndexCountBasedRetentionStrategy.java.1 AbstractIndexCountBasedRetentionStrategy.java.orig
88,91c88
<             .filter(indexName -> {
<               if (deflectorIndices.get(indexName) == null) return !false; //added shortcircuit to prevent NullPointerException
<               return !(deflectorIndices.get(indexName).contains(indexSet.getWriteIndexAlias()));
<             })
---
>             .filter(indexName -> !(deflectorIndices.get(indexName).contains(indexSet.getWriteIndexAlias())))

Steps to Reproduce (for bugs)

1. Set indices for number index rotation

Context

Logs cannot be rotated and housekeeper

Your Environment

Installed using sensible script provided by Elastic.co

• Graylog Version: 2.2.0+d9681cb
• Elasticsearch Version: 2.4.3
• MongoDB Version: 2.6.12
• Operating System: Ubuntu 14.04.5 LTS ( Linux ubuntu-14 3.13.0-106-generic Find out how the deflector alias can become a real index #153-Ubuntu SMP Tue Dec 6 15:44:32 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux)
• Browser version: Mac Safari Version 10.0.3 (12602.4.8)

[jalogisch]

@davidktw

thank you for your report I had double checked that on my lab:

2017-02-13T01:00:04.843+01:00 INFO  [AbstractRotationStrategy] Deflector index <long_hold_4> should be rotated, Pointing deflector to new index now!
2017-02-13T01:00:04.843+01:00 INFO  [MongoIndexSet] Cycling from <long_hold_4> to <long_hold_5>.
2017-02-13T01:00:04.843+01:00 INFO  [MongoIndexSet] Creating target index <long_hold_5>.
2017-02-13T01:00:04.862+01:00 INFO  [Indices] Created Graylog index template "long_hold-template" in Elasticsearch.
2017-02-13T01:00:05.045+01:00 INFO  [MongoIndexSet] Waiting for allocation of index <long_hold_5>.
2017-02-13T01:00:05.095+01:00 INFO  [MongoIndexSet] Index <long_hold_5> has been successfully allocated.
2017-02-13T01:00:05.095+01:00 INFO  [MongoIndexSet] Pointing index alias <long_hold_deflector> to new index <long_hold_5>.
2017-02-13T01:00:05.179+01:00 INFO  [SystemJobManager] Submitted SystemJob <5fcd00b0-f17f-11e6-a0ee-363366363531> [org.graylog2.indexer.indices.jobs.SetIndexReadOnlyAndCalculateRangeJob]
2017-02-13T01:00:05.179+01:00 INFO  [MongoIndexSet] Successfully pointed index alias <long_hold_deflector> to index <long_hold_5>.
2017-02-13T01:00:05.254+01:00 INFO  [AbstractRotationStrategy] Deflector index <radio_3> should be rotated, Pointing deflector to new index now!

currently I can't reproduce this. Maybe you have some more details.

thank you
jan

[joschi]

@davidktw Please post the output of the following command:

curl -X GET http://localhost:9200/_cat/indices?v http://localhost:9200/_cat/aliases?v

Installed using sensible script provided by Elastic.co

Which script exactly?

[jalogisch]

@davidktw

can you please comment on this.

[kroepke]

@davidktw Please reopen this if you can give us additional information on how to reproduce this.

Thank you!

[spencerwp]

This issue occurs if the active index is rotated while the retention thread is collecting indices.

This can happen if the elasticsearch node/cluster isn't strong enough, and responding too slowly to queries. Running the queries joschi posted in a situation like this will result in the active write index (that the alias points to) not showing up in the list of indices.

Under normal circumstances it is very rare that a rotation will happen during the retention clean-up.

[kroepke]

Thanks for the update, @spencerwp, we'll take a look.