New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Started org.graylog2.indexer.SetIndexReadOnlyJob hangs #1426

Closed
andreaconsadori opened this Issue Sep 16, 2015 · 17 comments

Comments

Projects
None yet
2 participants
@andreaconsadori

andreaconsadori commented Sep 16, 2015

under system - overview
this process continue to restart and i loose the olg message.

in server log i found

2015-09-16T15:05:53.774+02:00 ERROR [CreateNewSingleIndexRangeJob] Exception during index range calculation for index graylog2_374
java.lang.IllegalArgumentException: Invalid format: "1.442401649E12" is malformed at ".442401649E12"
        at org.joda.time.format.DateTimeFormatter.parseDateTime(DateTimeFormatter.java:899)
        at org.graylog2.indexer.ranges.EsIndexRangeService.timestampStatsOfIndex(EsIndexRangeService.java:258)
        at org.graylog2.indexer.ranges.EsIndexRangeService.calculateRange(EsIndexRangeService.java:216)
        at org.graylog2.indexer.ranges.CreateNewSingleIndexRangeJob.execute(CreateNewSingleIndexRangeJob.java:59)
        at org.graylog2.system.jobs.SystemJobManager$1.run(SystemJobManager.java:88)
        at com.codahale.metrics.InstrumentedScheduledExecutorService$InstrumentedRunnable.run(InstrumentedScheduledExecutorService.java:235)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
        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)
@joschi

This comment has been minimized.

Contributor

joschi commented Sep 16, 2015

Which version of Elasticsearch are you running?

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

root@logmanager:~# curl -XGET 'localhost:9200'
{
  "status" : 200,
  "name" : "Dragoness",
  "version" : {
    "number" : "1.3.4",
    "build_hash" : "a70f3ccb52200f8f2c87e9c370c6597448eb3e45",
    "build_timestamp" : "2014-09-30T09:07:17Z",
    "build_snapshot" : false,
    "lucene_version" : "4.9"
  },
  "tagline" : "You Know, for Search"
}
@joschi

This comment has been minimized.

Contributor

joschi commented Sep 16, 2015

Please upgrade to Elasticsearch 1.6.2 or 1.7.2 and check if the problem still persists.

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

upgrading elasticsearch now i can see the new messages but i loose the old one

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

and still have this issue

2015-09-16T15:41:04.879+02:00 WARN  [Indices] Unable to read creation_date for index graylog2_569
org.elasticsearch.transport.ActionNotFoundTransportException: No handler for action [indices:admin/get]
        at org.elasticsearch.transport.netty.MessageChannelHandler.handleRequest(MessageChannelHandler.java:210)
        at org.elasticsearch.transport.netty.MessageChannelHandler.messageReceived(MessageChannelHandler.java:111)
        at org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
        at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
        at org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
        at org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:296)
        at org.elasticsearch.common.netty.handler.codec.frame.FrameDecoder.unfoldAndFireMessageReceived(FrameDecoder.java:462)
        at org.elasticsearch.common.netty.handler.codec.frame.FrameDecoder.callDecode(FrameDecoder.java:443)
        at org.elasticsearch.common.netty.handler.codec.frame.FrameDecoder.messageReceived(FrameDecoder.java:303)
        at org.elasticsearch.common.netty.channel.SimpleChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamHandler.java:70)
        at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
        at org.elasticsearch.common.netty.channel.DefaultChannelPipeline$DefaultChannelHandlerContext.sendUpstream(DefaultChannelPipeline.java:791)
        at org.elasticsearch.common.netty.OpenChannelsHandler.handleUpstream(OpenChannelsHandler.java:74)
        at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
        at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
        at org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:268)
        at org.elasticsearch.common.netty.channel.Channels.fireMessageReceived(Channels.java:255)
        at org.elasticsearch.common.netty.channel.socket.nio.NioWorker.read(NioWorker.java:88)
        at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.process(AbstractNioWorker.java:108)
        at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318)
        at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioWorker.run(AbstractNioWorker.java:89)
        at org.elasticsearch.common.netty.channel.socket.nio.NioWorker.run(NioWorker.java:178)
        at org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
        at org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
        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)
@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

and this

2015-09-16T15:41:05.216+02:00 ERROR [CreateNewSingleIndexRangeJob] Exception during index range calculation for index graylog2_569
java.lang.IllegalArgumentException: Invalid format: "1.44240376E12" is malformed at ".44240376E12"
        at org.joda.time.format.DateTimeFormatter.parseDateTime(DateTimeFormatter.java:899)
        at org.graylog2.indexer.ranges.EsIndexRangeService.timestampStatsOfIndex(EsIndexRangeService.java:258)
        at org.graylog2.indexer.ranges.EsIndexRangeService.calculateRange(EsIndexRangeService.java:216)
        at org.graylog2.indexer.ranges.CreateNewSingleIndexRangeJob.execute(CreateNewSingleIndexRangeJob.java:59)
        at org.graylog2.system.jobs.SystemJobManager$1.run(SystemJobManager.java:88)
        at com.codahale.metrics.InstrumentedScheduledExecutorService$InstrumentedRunnable.run(InstrumentedScheduledExecutorService.java:235)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask.run(FutureTask.java:262)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
        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)
@joschi

This comment has been minimized.

Contributor

joschi commented Sep 16, 2015

Please recalculate index ranges (System -> Indices -> Maintenance -> Recalculate index ranges).

For better readability, please wrap your log messages in three single quotes (https://help.github.com/articles/github-flavored-markdown/#fenced-code-blocks) like this:

```
Some log lines…
```
@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

nothing change, there's a strange information if i go under (System -> Indices -> Maintenance)
some indicies says "graylog2_691 Contains messages up to 46 years ago"
and graylog are deleting them due to retention policy
also see this image, this task seems to persist
http://www.filedropper.com/systemjobs1

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

here the indices screenshot
http://www.filedropper.com/indices

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

it continue to create new indices

2015-09-16T16:12:45.025+02:00 ERROR [CreateNewSingleIndexRangeJob] Exception during index range calculation for index graylog2_759
java.lang.IllegalArgumentException: Invalid format: "1.442412334E12" is malformed at ".442412334E12"

graylog2_759 Contains messages up to 46 years ago (1,3MiB / 1,691 messages) Load Details / Actions
Range re-calculated 2015-09-16T16:12:36.419+02:00 in 4ms. 1 segments, 0 open search contexts, 0 deleted messages

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

if i change rotation_strategy from time to count the issue stop... but i need to fix 14days maximum of archived logs

@joschi

This comment has been minimized.

Contributor

joschi commented Sep 16, 2015

Please post the output of the following cURL command:

curl -XGET 'http://localhost:9200/graylog2_*/message/_search?search_type=count&pretty=true' -d '{
  "aggregations": {
    "ts_stats": {
      "stats": {
        "field": "timestamp"
      }
    }
  }
}'

Also replace graylog2_* in that command with one of your Graylog indices in Elasticsearch and post the output of that command.

@joschi

This comment has been minimized.

Contributor

joschi commented Sep 16, 2015

Just for comparison, the output for that command on a small development setup with Elasticsearch 1.7.1 is as follows:

{
  "took" : 13,
  "timed_out" : false,
  "_shards" : {
    "total" : 40,
    "successful" : 40,
    "failed" : 0
  },
  "hits" : {
    "total" : 906945,
    "max_score" : 0.0,
    "hits" : [ ]
  },
  "aggregations" : {
    "ts_stats" : {
      "count" : 906945,
      "min" : 1.440667997898E12,
      "max" : 1.4424108743E12,
      "avg" : 1.4410843135693894E12,
      "sum" : 1.30698421277018982E18,
      "min_as_string" : "2015-08-27 09:33:17.898",
      "max_as_string" : "2015-09-16 13:41:14.300",
      "avg_as_string" : "2015-09-01 05:11:53.569",
      "sum_as_string" : "41418650-12-14 05:56:29.824"
    }
  }
}

@joschi joschi self-assigned this Sep 16, 2015

@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 16, 2015

  "took" : 504,
  "timed_out" : false,
  "_shards" : {
    "total" : 8,
    "successful" : 8,
    "failed" : 0
  },
  "hits" : {
    "total" : 751630,
    "max_score" : 0.0,
    "hits" : [ ]
  },
  "aggregations" : {
    "ts_stats" : {
      "count" : 751630,
      "min" : 1.442407309E12,
      "max" : 1.442417979E12,
      "avg" : 1.4424162389379087E12,
      "sum" : 1.08416331767290022E18
    }
  }
}
@joschi

This comment has been minimized.

Contributor

joschi commented Sep 16, 2015

Please verify that you're only running Elasticsearch 1.6.x or 1.7.x. (actually ES 1.5.x and newer) and that the timestamp field been assigned the type date in the index mapping.

You can print the message mapping using the following curl command:

curl -XGET 'http://localhost:9200/graylog2_*/message/_mapping?pretty=true'

joschi added a commit that referenced this issue Sep 16, 2015

Use min/max instead of stats aggregation for index timestamp stats
Using the stats aggregation involved calculating unused values like sum and
average. Additionally we changed the parsing of the min/max values from using
the string representation to the numeric (double) representation which should
eliminate some error conditions, especially with older Elasticsearch versions.

Fixes #1426
@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 17, 2015

"timestamp" : {
            "type" : "date",
            "doc_values" : true,
            "format" : "yyyy-MM-dd HH:mm:ss.SSS"
root@logmanager:~# dpkg -l elasticsearch
Voluto=U (non noto)/I (installato)/R (rimosso)/P (rimosso totale)/H (in attesa)
| Stato=Non/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(nessuno)/R (reinstallazione richiesta) (Stato,Err: maiuscolo=grave)
||/ Nome                                       Versione                   Architettura               Descrizione
+++-==========================================-==========================-==========================-=========================================================================================
ii  elasticsearch                              1.7.2                      all                        Open Source, Distributed, RESTful Search Engine
@andreaconsadori

This comment has been minimized.

andreaconsadori commented Sep 17, 2015

after change rotation_strategy from time to count the issue stop

@joschi joschi closed this in 7e0b92d Sep 21, 2015

@joschi joschi added the bug label Sep 21, 2015

@joschi joschi added this to the 1.2.1 milestone Sep 21, 2015

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment