Skip to content
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

Improve registry file migration performance #20717

Merged
merged 5 commits into from
Aug 25, 2020

Conversation

urso
Copy link

@urso urso commented Aug 20, 2020

What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min

Benchmark results with fix (migration 100k entries took ~7.6s):

BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS

Checklist

  • My code follows the style guidelines of this project
  • I have commented my code, particularly in hard-to-understand areas
    - [ ] I have made corresponding changes to the documentation
    - [ ] I have made corresponding change to the default configuration files
  • I have added tests that prove my fix is effective or that my feature works
  • I have added an entry in CHANGELOG.next.asciidoc or CHANGELOG-developer.next.asciidoc.

Related issues

The registry uses a checkpoint-check that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disable
when migration the old registry file.
During migration the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.
@urso urso added bug Filebeat Filebeat needs_backport PR is waiting to be backported to other branches. labels Aug 20, 2020
@botelastic botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Aug 20, 2020
@urso urso added the Team:Services (Deprecated) Label for the former Integrations-Services team label Aug 20, 2020
@elasticmachine
Copy link
Collaborator

Pinging @elastic/integrations-services (Team:Services)

@botelastic botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Aug 20, 2020
@urso urso added the review label Aug 20, 2020
@elasticmachine
Copy link
Collaborator

elasticmachine commented Aug 20, 2020

💔 Tests Failed

Pipeline View Test View Changes Artifacts preview

Expand to view the summary

Build stats

  • Build Cause: [Pull request #20717 updated]

  • Start Time: 2020-08-21T16:50:05.228+0000

  • Duration: 70 min 45 sec

Test stats 🧪

Test Results
Failed 105
Passed 17930
Skipped 1827
Total 19862

Test errors

Expand to view the tests failures

  • Name: Build and Test / Auditbeat oss Linux / test_dashboards – auditbeat.tests.system.test_base.Test

    • Age: 1
    • Duration: 0.384
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_dev_tool_export_dashboard_by_id – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.32
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_dev_tool_export_dashboard_by_id_from_space – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.302
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_dev_tool_export_dashboard_from_yml – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.212
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_export_dashboard_cmd_export_dashboard_by_id – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.455
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_export_dashboard_cmd_export_dashboard_by_id_and_decoding – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.252
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_export_dashboard_cmd_export_dashboard_from_yml – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.248
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_load_dashboard – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.342
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_load_dashboard_into_space – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.785
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_load_only_index_patterns – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.141
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Libbeat / Libbeat oss / test_load_without_dashboard – libbeat.tests.system.test_dashboard.Test

    • Age: 1
    • Duration: 0.223
    • Error Details: AssertionError: Expected exit code to be 0, but it was 1
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_114_coredns – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 90.004
    • Error Details: Failed: Timeout >90.0s
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_115_coredns – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.222
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_116_ibmmq – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.142
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_117_ibmmq – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.125
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_118_ibmmq – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.129
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_119_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.126
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_120_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.126
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_121_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.161
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_122_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.152
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_123_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.122
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_124_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.121
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_125_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.131
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_126_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.13
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_127_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.215
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_128_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.126
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_129_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.211
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_130_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.244
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_131_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.212
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_132_o365 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.216
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_133_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.213
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_134_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.209
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_135_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.207
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_136_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.21
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_137_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.208
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_138_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.212
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_139_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.209
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_140_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.208
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_141_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.203
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_142_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.216
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_143_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.245
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_144_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.268
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_145_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.247
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_146_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.197
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_147_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.203
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_148_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.199
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_149_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.206
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_150_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.214
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_151_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.217
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_152_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.209
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_153_gsuite – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.199
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_154_sonicwall – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.199
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_155_sonicwall – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.195
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_156_infoblox – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.192
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_157_microsoft – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.232
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_158_microsoft – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.249
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_159_squid – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.222
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_160_googlecloud – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.194
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_161_googlecloud – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.198
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_162_googlecloud – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.196
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_163_googlecloud – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.194
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_164_rapid7 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.203
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_165_f5 – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.194
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_166_barracuda – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.19
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_167_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.203
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_168_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.203
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_169_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.187
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_170_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.192
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_171_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.196
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_172_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.228
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_173_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.257
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_174_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.228
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_175_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.19
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_176_sophos – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.199
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_177_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.186
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_178_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.193
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_179_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.194
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_180_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.19
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_181_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.194
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_182_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.202
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_183_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.186
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_184_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.199
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_185_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.206
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_186_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.238
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_187_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.25
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_188_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.204
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_189_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.191
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_190_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.191
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_191_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.19
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_192_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.193
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_193_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.189
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_194_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.195
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_195_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.198
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_196_cisco – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.189
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_197_suricata – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.204
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_198_suricata – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.273
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_199_suricata – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.272
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_200_bluecoat – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.246
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_201_envoyproxy – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.229
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.
  • Name: Build and Test / Filebeat x-pack / test_fileset_file_202_envoyproxy – x-pack.filebeat.tests.system.test_xpack_modules.XPackTest

    • Age: 1
    • Duration: 10.187
    • Error Details: beat.beat.TimeoutError: Timeout waiting for 'cond' to be true. Waited 10 seconds.

Steps errors

Expand to view the steps failures

  • Name: Mage build test

    • Description: mage build test

    • Duration: 35 min 21 sec

    • Start Time: 2020-08-21T17:13:19.172+0000

    • log

  • Name: Mage build test

    • Description: mage build test

    • Duration: 11 min 41 sec

    • Start Time: 2020-08-21T17:13:24.491+0000

    • log

  • Name: Mage build test

    • Description: mage build test

    • Duration: 27 min 44 sec

    • Start Time: 2020-08-21T17:13:21.230+0000

    • log

  • Name: Make test

    • Description: make -C generator/_templates/metricbeat test

    • Duration: 6 min 7 sec

    • Start Time: 2020-08-21T17:28:12.883+0000

    • log

  • Name: Recursively delete the current directory from the workspace

    • Description: script returned exit code 2

    • Duration: 1 min 8 sec

    • Start Time: 2020-08-21T17:34:35.700+0000

    • log

Log output

Expand to view the last 100 lines of log output

[2020-08-21T17:58:54.222Z] + tar --version
[2020-08-21T17:58:54.520Z] + tar -xpf source.tgz
[2020-08-21T17:59:04.862Z] + rm source.tgz
[2020-08-21T17:59:04.874Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats
[2020-08-21T17:59:04.896Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Lint
[2020-08-21T17:59:04.993Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Elastic-Agent-x-pack
[2020-08-21T17:59:05.068Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Winlogbeat-oss
[2020-08-21T17:59:05.146Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Elastic-Agent-Mac-OS-X
[2020-08-21T17:59:05.223Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/dockerlogbeat
[2020-08-21T17:59:05.300Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-crosscompile
[2020-08-21T17:59:05.375Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Journalbeat
[2020-08-21T17:59:05.451Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Functionbeat-x-pack
[2020-08-21T17:59:05.530Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Generators-Metricbeat-Linux
[2020-08-21T17:59:05.612Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Filebeat-x-pack-Mac-OS-X
[2020-08-21T17:59:05.693Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Elastic-Agent-x-pack-Windows
[2020-08-21T17:59:05.776Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-oss-Mac-OS-X
[2020-08-21T17:59:05.855Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Packetbeat-Linux
[2020-08-21T17:59:05.940Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-OSS-Unit-tests
[2020-08-21T17:59:06.016Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Filebeat-Mac-OS-X
[2020-08-21T17:59:06.096Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Heartbeat-oss
[2020-08-21T17:59:06.173Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-x-pack
[2020-08-21T17:59:06.252Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Heartbeat-Windows
[2020-08-21T17:59:06.328Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-oss-Windows
[2020-08-21T17:59:06.404Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Winlogbeat-Windows-x-pack
[2020-08-21T17:59:06.481Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-x-pack-Windows
[2020-08-21T17:59:06.558Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-Mac-OS-X
[2020-08-21T17:59:06.640Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack-Mac-OS-X
[2020-08-21T17:59:06.717Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Filebeat-x-pack-Windows
[2020-08-21T17:59:06.798Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Winlogbeat-Windows
[2020-08-21T17:59:06.874Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-crosscompile
[2020-08-21T17:59:06.950Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Heartbeat-Mac-OS-X
[2020-08-21T17:59:07.032Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Filebeat-Windows
[2020-08-21T17:59:07.110Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Libbeat-x-pack
[2020-08-21T17:59:07.190Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Packetbeat-Mac-OS-X
[2020-08-21T17:59:07.266Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-oss-Linux
[2020-08-21T17:59:07.343Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Auditbeat-x-pack-Mac-OS-X
[2020-08-21T17:59:07.427Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Functionbeat-Mac-OS-X-x-pack
[2020-08-21T17:59:07.503Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Functionbeat-Windows
[2020-08-21T17:59:07.590Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Generators-Beat-Mac-OS-X
[2020-08-21T17:59:07.670Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Packetbeat-Windows
[2020-08-21T17:59:07.750Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack-Windows
[2020-08-21T17:59:07.830Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-Windows
[2020-08-21T17:59:07.918Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Generators-Beat-Linux
[2020-08-21T17:59:07.994Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Generators-Metricbeat-Mac-OS-X
[2020-08-21T17:59:08.073Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Filebeat-oss
[2020-08-21T17:59:08.152Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Libbeat-oss
[2020-08-21T17:59:08.231Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-OSS-Go-Integration-tests
[2020-08-21T17:59:08.309Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Filebeat-x-pack
[2020-08-21T17:59:08.387Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-OSS-Python-Integration-tests
[2020-08-21T17:59:08.466Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack
[2020-08-21T17:59:08.865Z] + cat
[2020-08-21T17:59:08.865Z] + /usr/local/bin/runbld ./runbld-script --job-name elastic+beats+pull-request
[2020-08-21T17:59:08.865Z] Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF8
[2020-08-21T17:59:15.464Z] runbld>>> runbld started
[2020-08-21T17:59:15.464Z] runbld>>> 1.6.12/f45d832f2ba0aa2722ab4ec1fda8ad140f027f8b
[2020-08-21T17:59:16.856Z] runbld>>> The following profiles matched the job 'elastic+beats+pull-request' in order of occurrence in the config (last value wins).
[2020-08-21T17:59:16.856Z] runbld>>> Matches in the system config:
[2020-08-21T17:59:16.856Z] runbld>>> - Matched ^elastic\+beats
[2020-08-21T17:59:16.856Z] runbld>>> - Matched ^elastic\+beats\+pull-request
[2020-08-21T17:59:18.244Z] runbld>>> Debug logging enabled.
[2020-08-21T17:59:18.244Z] runbld>>> Storing result
[2020-08-21T17:59:18.244Z] runbld>>> Store result: created {:total 2, :successful 2, :failed 0} 1
[2020-08-21T17:59:18.244Z] runbld>>> BUILD: https://c150076387b5421f9154dfbf536e5c60.us-west1.gcp.cloud.es.io:9243/build-1597739501209/t/20200821175917-960C65E5
[2020-08-21T17:59:18.244Z] runbld>>> Adding system facts.
[2020-08-21T17:59:19.188Z] runbld>>> Adding vcs info for the latest commit:  32a172555b366b8635288b9de2a803889c6ef6d7
[2020-08-21T17:59:19.188Z] runbld>>> >>>>>>>>>>>> SCRIPT EXECUTION BEGIN >>>>>>>>>>>>
[2020-08-21T17:59:19.188Z] runbld>>> Adding /usr/lib/jvm/java-8-openjdk-amd64/bin to the path.
[2020-08-21T17:59:19.449Z] Processing JUnit reports with runbld...
[2020-08-21T17:59:19.449Z] + echo 'Processing JUnit reports with runbld...'
[2020-08-21T17:59:19.711Z] runbld>>> <<<<<<<<<<<< SCRIPT EXECUTION END <<<<<<<<<<<<
[2020-08-21T17:59:19.711Z] runbld>>> DURATION: 23ms
[2020-08-21T17:59:19.711Z] runbld>>> STDOUT: 40 bytes
[2020-08-21T17:59:19.711Z] runbld>>> STDERR: 49 bytes
[2020-08-21T17:59:19.711Z] runbld>>> WRAPPED PROCESS: SUCCESS (0)
[2020-08-21T17:59:19.711Z] runbld>>> Searching for build metadata in /var/lib/jenkins/workspace/Beats_beats_PR-20717
[2020-08-21T17:59:20.653Z] runbld>>> Storing build metadata: 
[2020-08-21T17:59:20.653Z] runbld>>> Adding test report.
[2020-08-21T17:59:20.653Z] runbld>>> Searching for junit test output files with the pattern: TEST-.*\.xml$ in: /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats
[2020-08-21T17:59:21.596Z] runbld>>> Found 137 test output files
[2020-08-21T17:59:22.984Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack/x-pack/metricbeat/build/TEST-go-integration-openmetrics.xml
[2020-08-21T17:59:22.984Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack/x-pack/metricbeat/build/TEST-go-integration-activemq.xml
[2020-08-21T17:59:22.984Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack/x-pack/metricbeat/build/TEST-go-integration-iis.xml
[2020-08-21T17:59:22.984Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack/x-pack/metricbeat/build/TEST-go-integration-istio.xml
[2020-08-21T17:59:22.984Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-x-pack/x-pack/metricbeat/build/TEST-go-integration-tomcat.xml
[2020-08-21T17:59:22.984Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-OSS-Go-Integration-tests/metricbeat/build/TEST-go-integration-graphite.xml
[2020-08-21T17:59:23.245Z] runbld>>> No testsuite node found in /var/lib/jenkins/workspace/Beats_beats_PR-20717/src/github.com/elastic/beats/Metricbeat-OSS-Go-Integration-tests/metricbeat/build/TEST-go-integration-windows.xml
[2020-08-21T17:59:24.189Z] runbld>>> Test output logs contained: Errors: 0 Failures: 105 Tests: 19711 Skipped: 1560
[2020-08-21T17:59:24.451Z] runbld>>> Storing result
[2020-08-21T17:59:24.451Z] runbld>>> FAILURES: 105
[2020-08-21T17:59:46.427Z] runbld>>> Store result: updated {:total 2, :successful 2, :failed 0} 2
[2020-08-21T17:59:46.427Z] runbld>>> BUILD: https://c150076387b5421f9154dfbf536e5c60.us-west1.gcp.cloud.es.io:9243/build-1597739501209/t/20200821175917-960C65E5
[2020-08-21T17:59:46.427Z] runbld>>> Email notification disabled by environment variable.
[2020-08-21T17:59:46.427Z] runbld>>> Slack notification disabled by environment variable.
[2020-08-21T17:59:49.922Z] Running on Jenkins in /var/lib/jenkins/workspace/Beats_beats_PR-20717
[2020-08-21T17:59:50.025Z] [INFO] getVaultSecret: Getting secrets
[2020-08-21T17:59:50.083Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2020-08-21T17:59:50.889Z] + chmod 755 generate-build-data.sh
[2020-08-21T17:59:50.890Z] + ./generate-build-data.sh https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-20717/ https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-20717/runs/4 FAILURE 4185401
[2020-08-21T17:59:50.890Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-20717/runs/4/steps/?limit=10000 -o steps-info.json
[2020-08-21T17:59:54.118Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-20717/runs/4/tests/?status=FAILED -o tests-errors.json

@urso
Copy link
Author

urso commented Aug 21, 2020

CI seams quite unstable the last few days. All registry related and registry migration tests did pass.

@kvch kvch merged commit 03748b3 into elastic:master Aug 25, 2020
kvch pushed a commit to kvch/beats that referenced this pull request Aug 25, 2020
## What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

## Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration, the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately, the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

```
BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min
```

Benchmark results with the fix (migration 100k entries took ~7.6s):

```
BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS
```

Closes elastic#20705

(cherry picked from commit 03748b3)
@kvch kvch added v7.10.0 and removed needs_backport PR is waiting to be backported to other branches. labels Aug 25, 2020
kvch pushed a commit to kvch/beats that referenced this pull request Aug 25, 2020
## What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

## Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration, the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately, the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

```
BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min
```

Benchmark results with the fix (migration 100k entries took ~7.6s):

```
BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS
```

Closes elastic#20705

(cherry picked from commit 03748b3)
@kvch kvch added the v7.9.1 label Aug 25, 2020
kvch added a commit that referenced this pull request Aug 25, 2020
## What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

## Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration, the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately, the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

```
BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min
```

Benchmark results with the fix (migration 100k entries took ~7.6s):

```
BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS
```

Closes #20705

(cherry picked from commit 03748b3)

Co-authored-by: Steffen Siering <steffen.siering@elastic.co>
kvch added a commit that referenced this pull request Aug 25, 2020
#20769)

* Improve registry file migration performance (#20717)

## What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

## Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration, the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately, the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

```
BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min
```

Benchmark results with the fix (migration 100k entries took ~7.6s):

```
BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS
```

Closes #20705

(cherry picked from commit 03748b3)

* fix changelog

Co-authored-by: Steffen Siering <steffen.siering@elastic.co>
melchiormoulin pushed a commit to melchiormoulin/beats that referenced this pull request Oct 14, 2020
## What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

## Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration, the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately, the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

```
BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min
```

Benchmark results with the fix (migration 100k entries took ~7.6s):

```
BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS
```

Closes elastic#20705
leweafan pushed a commit to leweafan/beats that referenced this pull request Apr 28, 2023
…formance (elastic#20769)

* Improve registry file migration performance (elastic#20717)

## What does this PR do?

Ensure that fsync is called only once after the migration of old state entries is complete.

## Why is it important?

The registry uses a checkpoint-predicate that when true writes all state to
disk and calls fsync. The checkpoint operation is supposed to be disabled
when migration the old registry file.
During migration, the old state will be directly copied (after cleanup
and schema changes are applied). The old state will only be deleted
after the migration of all states is complete.

Unfortunately, the checkpoint predicate did return true, instead of
false, which did trigger a checkpoint operation per state to be
migrated. The fix disables fsync, and now finalizes the migration by
calling Checkpoint directly.

The PR also provides a benchmark (each "op" is one migration attempt). Before this fix (go test did kill the run after 10min for 10k entries):

```
BenchmarkMigration0To1/1-32  	             286	   4203353 ns/op
BenchmarkMigration0To1/10-32 	              34	  35730680 ns/op
BenchmarkMigration0To1/100-32         	       2	 720890839 ns/op
BenchmarkMigration0To1/1000-32        	       1	31633569085 ns/op
... test timed out after 10min
```

Benchmark results with the fix (migration 100k entries took ~7.6s):

```
BenchmarkMigration0To1/1-32  	             274	   4371400 ns/op
BenchmarkMigration0To1/10-32 	             259	   4639209 ns/op
BenchmarkMigration0To1/100-32         	     100	  13374147 ns/op
BenchmarkMigration0To1/1000-32        	      13	 104220944 ns/op
BenchmarkMigration0To1/10000-32       	       2	 916656798 ns/op
BenchmarkMigration0To1/100000-32      	       1	7616648790 ns/op
PASS
```

Closes elastic#20705

(cherry picked from commit c2be4a7)

* fix changelog

Co-authored-by: Steffen Siering <steffen.siering@elastic.co>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Filebeat Filebeat review Team:Services (Deprecated) Label for the former Integrations-Services team v7.9.1 v7.10.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[v7.9.0] Filebeat constantly trying to migrate the registry to a new format
4 participants