Logstash: Java execution reorders events even with 1 pipeline worker

[jsvd]

Java execution seems to reorder the batch when using conditionals:

input {
  generator {
    lines => [
      "line 1",
      "line a",
      "line 2",
      "line b",
      "line 3",
      "line c"
    ]
    count => 1
  }
}

filter {
  grok { match => [ "message", "^line \d$" ] }

  if "_grokparsefailure" not in [tags] {
    ruby { code => '1+1' }
  } else {
    ruby { code => '1+1' }
  }
}

output { stdout { codec => line } }

/tmp/logstash-7.2.0 % bin/logstash -f test.conf -w 1 
2019-07-05T12:11:59.362Z overcraft.lan line 1
2019-07-05T12:11:59.375Z overcraft.lan line 2
2019-07-05T12:11:59.377Z overcraft.lan line 3
2019-07-05T12:11:59.375Z overcraft.lan line a
2019-07-05T12:11:59.376Z overcraft.lan line b
2019-07-05T12:11:59.377Z overcraft.lan line c
/tmp/logstash-7.2.0 % bin/logstash -f test.conf -w 1 --java-execution=false
2019-07-05T12:22:43.944Z overcraft.lan line 1
2019-07-05T12:22:43.955Z overcraft.lan line a
2019-07-05T12:22:43.956Z overcraft.lan line 2
2019-07-05T12:22:43.956Z overcraft.lan line b
2019-07-05T12:22:43.957Z overcraft.lan line 3
2019-07-05T12:22:43.957Z overcraft.lan line c

Right now the workaround is to use java-execution=false.

[colinsurprenant]

we've never officially guaranteed strict ordering but it's been an undocumented "feature" that using -w 1 would preserve ordering and lots of users do rely on this behaviour. I think we should fix that and also decide if we make it an official behaviour and add docs and tests/specs for it.

[lassebv]

Hi,

I am the one that found this bug and reported it through our Elastic license. I just wanted to point out that the documentation actually does guarantee a strict ordering. It is at least how I understand the following phrase in the documentation for the aggregate filter (https://www.elastic.co/guide/en/logstash/current/plugins-filters-aggregate.html):

You should be very careful to set Logstash filter workers to 1 (-w 1 flag) for this filter to work correctly otherwise events may be processed out of sequence and unexpected results will occur.

[colinsurprenant]

@lassebv it was never officially guaranteed in LS core but you are right that this specific filter does rely on this behaviour. Note that this filter was not originally authored by Elastic but nonetheless logstash team members at the time were involved in the initial development and this behaviour has been implicit in the way the pipeline has been working.
In any cases, we are working on restoring this behaviour in the Java execution and a PR is in flight #11020

[lassebv]

Awesome :)

[colinsurprenant]

• This is now fixed per #11524 but only in master (8.0) and 7.7.
• For 7.6 the decided not to backport until we fix #11550 and for now the workaround will be to use the Ruby execution (--pipeline.workers 1 --java-execution false)