Graylog2-server: Slow CSV export - chunk window too small

[dhohengassner]

Problem Description

At our System search queries performing pretty ok but csv exports are very slow.

We enabled debugging (was not enabled before) and think our issue is related to a too small scroll chunk size.

2018-10-03T07:46:28.828Z DEBUG [ScrollResult] [fcc06295aa85fe3fc77517a5f09ff229][399] New scroll id <ScrollID>, number of hits in chunk: 10
2018-10-03T07:46:28.828Z DEBUG [SearchResource] [fcc06295aa85fe3fc77517a5f09ff229] Writing scroll chunk with 10 messages
2018-10-03T07:46:28.828Z DEBUG [ScrollChunkWriter] [258] Writing chunk 399

Steps to Reproduce (for bugs)

Using the API we facing slow download speed:

curl -H 'Accept: text/csv' -X GET 'localhost:9000/api/search/universal/relative/export?query=msdhcp&range=0&fields=message' --output test.csv

2018-10-03T08:29:03.181Z DEBUG [ScrollResult] [<ID>] Starting scroll request for query msdhcp
2018-10-03T08:29:03.181Z DEBUG [SearchResource] [<ID>] Scroll result contains a total of 4029 messages
2018-10-03T08:29:03.185Z DEBUG [ScrollResult] [<ID>][0] New scroll id <ScrollID>, number of hits in chunk: 10
2018-10-03T08:29:03.186Z DEBUG [SearchResource] [<ID>] Writing scroll chunk with 10 messages
2018-10-03T08:29:03.187Z DEBUG [ScrollChunkWriter] [261] Writing chunk 0
2018-10-03T08:29:03.207Z DEBUG [ScrollResult] [<ID>][1] New scroll id <ScrollID>, number of hits in chunk: 10
2018-10-03T08:29:03.207Z DEBUG [SearchResource] [<ID>] Writing scroll chunk with 10 messages
2018-10-03T08:29:03.207Z DEBUG [ScrollChunkWriter] [261] Writing chunk 1
.. reading the next chunks
2018-10-03T08:29:05.230Z DEBUG [ScrollResult] [<ID>][402] New scroll id <ScrollID>, number of hits in chunk: 9
2018-10-03T08:29:05.231Z DEBUG [SearchResource] [<ID>] Writing scroll chunk with 9 messages
2018-10-03T08:29:05.231Z DEBUG [ScrollChunkWriter] [261] Writing chunk 402
2018-10-03T08:29:05.234Z DEBUG [ScrollResult] [<ID>] Reached end of scroll results.
2018-10-03T08:29:05.234Z DEBUG [SearchResource] [<ID>] Reached end of scroll result.

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  4242    0  4242    0     0   7233      0 --:--:-- --:--:-- --:--:--  7238

If we set a limit the chunk size increases to the limit size - but as expected we just get the limited amount of messages. That means in this case we get only 1 chunk with 18 messages - queried for 4029 messages:

curl -H 'Accept: text/csv' -X GET 'localhost:9000/api/search/universal/relative/export?query=msdhcp&range=0&fields=message&limit=18' --output test.csv

2018-10-03T08:28:34.215Z DEBUG [ScrollResult] [<ID>] Starting scroll request for query msdhcp
2018-10-03T08:28:34.215Z DEBUG [SearchResource] [<ID>] Scroll result contains a total of 4029 messages
2018-10-03T08:28:34.217Z DEBUG [ScrollResult] [<ID>][0] New scroll id <ScrollID>, number of hits in chunk: 18
2018-10-03T08:28:34.217Z DEBUG [SearchResource] [<ID>] Writing scroll chunk with 18 messages
2018-10-03T08:28:34.217Z DEBUG [ScrollChunkWriter] [260] Writing chunk 0
2018-10-03T08:28:34.234Z DEBUG [ScrollResult] [<ID>] clearScroll for query successful: true

  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  924k    0  924k    0     0   437k      0 --:--:--  0:00:02 --:--:--  438k

Further investigations

It looks to me this is the place the chunk size gets calculated:
build new chunk
get hits for new chunk
ES API method to get hits

It looks like the 10 messages for chunk size is a ES default and I found no possibility to overwrite this value.

In older issues it seems there was an default for the chunk size of 500.

To me it looks like a bug that we cannot set the chunk size for the csv export and I do not understand the relationship to the limit parameter.

• Graylog Version: 2.4.4
• Elasticsearch Version: 5.6.10
• Operating System: ubuntu 16.04

[universam1]

Good catch, looks like a bug, I was searching for a way to define the scroll window as well without success.

[kroepke]

@dhohengassner Indeed, this seems to have been broken when switching to the HTTP client.
The relevant change is https://github.com/Graylog2/graylog2-server/commit/4213a2257429b6a0803ab1b52c39a6a35fbde889#diff-0535e1ddeae5e21d28fb695a2f63f1f8L215

Previously the 500 was hardcoded, since then it defaulted to the elasticsearch default value, which is obviously way too low.

Thanks for all the work that you put into tracking this down, I'll check with the team for a target version of the fix.

I'm thinking we should default back to 500 and at the same time allowing the API to set the scroll chunk size explicitly.

[dhohengassner]

Thanks for taking a look into that.

I would appreciate a parameter in the config file to adapt this setting.
This would allow a custom setting for UI users I think.

Thanks for your work!

[jonattta]

Looking forward to that fix as well

[keaoner]

And me to :+1:

[keaoner]

hi,
Do you have a release date for graylog version 2.5? because we are waiting for the patch for csv downloads before going into production

best regards

[kroepke]

I'm sorry, we don't have a date set yet.

[universam1]

Since this is confirmed bug, does it really need to wait on a version upgrade or cannot it be considered as part of a bugfix release earlier?

[bernd]

@keaoner @universam1 The Graylog 2.5 release including this bug fix will be available in the first week of December.