Skip to content

Filebeat Module Tests are Flaky #9502

Closed
Closed
Filebeat Module Tests are Flaky#9502
Assignees
ruflin
Labels
FilebeatFilebeatTeam:IntegrationsLabel for the Integrations teamflaky-testUnstable or unreliable test cases.
@andrewvc

Description

@andrewvc
andrewvc
opened on Dec 12, 2018

Flaky Test

  • Test Name: Multiple failures, see below:
test_modules.Test.test_fileset_file_0_kafka
test_modules.Test.test_fileset_file_11_kibana
test_modules.Test.test_fileset_file_14_elasticsearch
test_modules.Test.test_fileset_file_15_elasticsearch
test_modules.Test.test_fileset_file_17_elasticsearch
test_modules.Test.test_fileset_file_21_elasticsearch
test_modules.Test.test_fileset_file_22_icinga
test_modules.Test.test_fileset_file_23_icinga
test_modules.Test.test_fileset_file_24_icinga
test_modules.Test.test_fileset_file_26_auditd

Error Message
The following expected object was not found:
 {
  "elasticsearch.gc.phase.cpu_time.sys_sec": "0.00",
  "elasticsearch.gc.phase.name": "CMS Initial Mark",
  "elasticsearch.gc.heap.size_kb": "253440",
  "elasticsearch.gc.phase.cpu_time.user_sec": "0.01",
  "elasticsearch.gc.old_gen.size_kb": "174784",
  "elasticsearch.gc.phase.duration_sec": "0.0021716",
  "service.name": "elasticsearch",
  "@timestamp": "2018-03-03T14:37:06.157Z",
  "input.type": "log",
  "event.module": "elasticsearch",
  "elasticsearch.gc.heap.used_kb": "142444",
  "elasticsearch.gc.old_gen.used_kb": "131804",
  "elasticsearch.gc.jvm_runtime_sec": "14597.826",
  "elasticsearch.gc.phase.cpu_time.real_sec": "0.00",
  "message": "2018-03-03T19:37:06.157+0500: 14597.826: [GC (CMS Initial Mark) [1 CMS-initial-mark: 131804K(174784K)] 142444K(253440K), 0.0021716 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]",
  "event.dataset": "gc",
  "log.offset": 0
}
Searched in: 
[
  {
    "log": {
      "file": {
        "path": "/go/src/github.com/elastic/beats/filebeat/module/elasticsearch/gc/test/test.log"
      },
      "offset": 0
    },
    "service": {
      "name": "elasticsearch"
    },
    "@timestamp": "2018-03-03T14:37:06.157Z",
    "agent": {
      "ephemeral_id": "03168a4d-dc31-4ea9-9f39-0ced51aad6a1",
      "hostname": "1b026b5d4d05",
      "type": "filebeat",
      "id": "08ebce27-53ef-4801-9b76-aad8e2ebad70",
      "version": "7.0.0"
    },
    "host": {
      "name": "1b026b5d4d05"
    },
    "elasticsearch": {
      "gc": {
        "phase": {
          "cpu_time": {
            "real_sec": "0.00",
            "user_sec": "0.01",
            "sys_sec": "0.00"
          },
          "name": "CMS Initial Mark",
          "duration_sec": "0.0021716"
        },
        "old_gen": {
          "used_kb": "131804",
          "size_kb": "174784"
        },
        "jvm_runtime_sec": "14597.826",
        "heap": {
          "used_kb": "142444",
          "size_kb": "253440"
        }
      }
    },
    "input": {
      "type": "log"
    },
    "message": "2018-03-03T19:37:06.157+0500: 14597.826: [GC (CMS Initial Mark) [1 CMS-initial-mark: 131804K(174784K)] 142444K(253440K), 0.0021716 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]",
    "event": {
      "dataset": "gc",
      "module": "elasticsearch",
      "created": "2018-12-07T21:33:18.501Z"
    }
  },
  {
    "log": {
      "file": {
        "path": "/go/src/github.com/elastic/beats/filebeat/module/elasticsearch/gc/test/test.log"
      },
      "offset": 181
    },
    "service": {
      "name": "elasticsearch"
    },
    "@timestamp": "2018-06-11T01:53:11.382Z",
    "agent": {
      "ephemeral_id": "03168a4d-dc31-4ea9-9f39-0ced51aad6a1",
      "hostname": "1b026b5d4d05",
      "type": "filebeat",
      "id": "08ebce27-53ef-4801-9b76-aad8e2ebad70",
      "version": "7.0.0"
    },
    "host": {
      "name": "1b026b5d4d05"
    },
    "elasticsearch": {
      "gc": {
        "threads_total_stop_time_sec": "0.0083760",
        "stopping_threads_time_sec": "0.0000702",
        "jvm_runtime_sec": "1396138.752"
      }
    },
    "input": {
      "type": "log"
    },
    "message": "2018-06-11T01:53:11.382+0000: 1396138.752: Total time for which application threads were stopped: 0.0083760 seconds, Stopping threads took: 0.0000702 seconds",
    "event": {
      "dataset": "gc",
      "module": "elasticsearch",
      "created": "2018-12-07T21:33:18.501Z"
    }
  },
  {
    "log": {
      "file": {
        "path": "/go/src/github.com/elastic/beats/filebeat/module/elasticsearch/gc/test/test.log"
      },
      "offset": 339
    },
    "service": {
      "name": "elasticsearch"
    },
    "@timestamp": "2018-06-30T11:35:26.632Z",
    "agent": {
      "type": "filebeat",
      "hostname": "1b026b5d4d05",
      "ephemeral_id": "03168a4d-dc31-4ea9-9f39-0ced51aad6a1",
      "id": "08ebce27-53ef-4801-9b76-aad8e2ebad70",
      "version": "7.0.0"
    },
    "host": {
      "name": "1b026b5d4d05"
    },
    "elasticsearch": {
      "gc": {
        "phase": {
          "cpu_time": {
            "real_sec": "0.04",
            "user_sec": "0.12",
            "sys_sec": "0.00"
          },
          "weak_refs_processing_time_sec": "0.0003647",
          "name": "CMS Final Remark",
          "duration_sec": "0.0457689",
          "parallel_rescan_time_sec": "0.0148273",
          "class_unload_time_sec": "0.0188407",
          "scrub_symbol_table_time_sec": "0.0100207",
          "scrub_string_table_time_sec": "0.0005253"
        },
        "old_gen": {
          "used_kb": "277821",
          "size_kb": "349568"
        },
        "heap": {
          "used_kb": "391020",
          "size_kb": "506816"
        },
        "jvm_runtime_sec": "224.671",
        "young_gen": {
          "used_kb": "113198",
          "size_kb": "157248"
        }
      }
    },
    "input": {
      "type": "log"
    },
    "message": "2018-06-30T16:35:26.632+0500: 224.671: [GC (CMS Final Remark) [YG occupancy: 113198 K (157248 K)]224.671: [Rescan (parallel) , 0.0148273 secs]224.686: [weak refs processing, 0.0003647 secs]224.687: [class unloading, 0.0188407 secs]224.705: [scrub symbol table, 0.0100207 secs]224.715: [scrub string table, 0.0005253 secs][1 CMS-remark: 277821K(349568K)] 391020K(506816K), 0.0457689 secs] [Times: user=0.12 sys=0.00, real=0.04 secs]",
    "event": {
      "dataset": "gc",
      "module": "elasticsearch",
      "created": "2018-12-07T21:33:18.501Z"
    }
  }
]
-------------------- >> begin captured stdout << ---------------------
Using elasticsearch: http://elasticsearch:9200
Testing elasticsearch/gc on /go/src/github.com/elastic/beats/filebeat/tests/system/../../module/elasticsearch/gc/test/test.log

--------------------- >> end captured stdout << ----------------------


### Stack Trace

See the artifact for full traces. Here's one

File "/usr/lib/python2.7/unittest/case.py", line 329, in run
testMethod()
File "/go/src/github.com/elastic/beats/filebeat/build/python-env/local/lib/python2.7/site-packages/parameterized/parameterized.py", line 392, in standalone_func
return func(*(a + p.args), **p.kwargs)
File "/go/src/github.com/elastic/beats/filebeat/tests/system/test_modules.py", line 91, in test_fileset_file
cfgfile=cfgfile)
File "/go/src/github.com/elastic/beats/filebeat/tests/system/test_modules.py", line 150, in run_on_file
self._test_expected_events(test_file, objects)
File "/go/src/github.com/elastic/beats/filebeat/tests/system/test_modules.py", line 188, in _test_expected_events
pretty_json(ev), pretty_json(objects))
The following expected object was not found:
{
"elasticsearch.gc.phase.cpu_time.sys_sec": "0.00",
"elasticsearch.gc.phase.name": "CMS Initial Mark",
"elasticsearch.gc.heap.size_kb": "253440",
"elasticsearch.gc.phase.cpu_time.user_sec": "0.01",
"elasticsearch.gc.old_gen.size_kb": "174784",
"elasticsearch.gc.phase.duration_sec": "0.0021716",
"service.name": "elasticsearch",
"@timestamp": "2018-03-03T14:37:06.157Z",
"input.type": "log",
"event.module": "elasticsearch",
"elasticsearch.gc.heap.used_kb": "142444",
"elasticsearch.gc.old_gen.used_kb": "131804",
"elasticsearch.gc.jvm_runtime_sec": "14597.826",
"elasticsearch.gc.phase.cpu_time.real_sec": "0.00",
"message": "2018-03-03T19:37:06.157+0500: 14597.826: [GC (CMS Initial Mark) [1 CMS-initial-mark: 131804K(174784K)] 142444K(253440K), 0.0021716 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]",
"event.dataset": "gc",
"log.offset": 0
}
Searched in:
[
{
"log": {
"file": {
"path": "/go/src/github.com/elastic/beats/filebeat/module/elasticsearch/gc/test/test.log"
},
"offset": 0
},
"service": {
"name": "elasticsearch"
},
"@timestamp": "2018-03-03T14:37:06.157Z",
"agent": {
"ephemeral_id": "03168a4d-dc31-4ea9-9f39-0ced51aad6a1",
"hostname": "1b026b5d4d05",
"type": "filebeat",
"id": "08ebce27-53ef-4801-9b76-aad8e2ebad70",
"version": "7.0.0"
},
"host": {
"name": "1b026b5d4d05"
},
"elasticsearch": {
"gc": {
"phase": {
"cpu_time": {
"real_sec": "0.00",
"user_sec": "0.01",
"sys_sec": "0.00"
},
"name": "CMS Initial Mark",
"duration_sec": "0.0021716"
},
"old_gen": {
"used_kb": "131804",
"size_kb": "174784"
},
"jvm_runtime_sec": "14597.826",
"heap": {
"used_kb": "142444",
"size_kb": "253440"
}
}
},
"input": {
"type": "log"
},
"message": "2018-03-03T19:37:06.157+0500: 14597.826: [GC (CMS Initial Mark) [1 CMS-initial-mark: 131804K(174784K)] 142444K(253440K), 0.0021716 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]",
"event": {
"dataset": "gc",
"module": "elasticsearch",
"created": "2018-12-07T21:33:18.501Z"
}
},
{
"log": {
"file": {
"path": "/go/src/github.com/elastic/beats/filebeat/module/elasticsearch/gc/test/test.log"
},
"offset": 181
},
"service": {
"name": "elasticsearch"
},
"@timestamp": "2018-06-11T01:53:11.382Z",
"agent": {
"ephemeral_id": "03168a4d-dc31-4ea9-9f39-0ced51aad6a1",
"hostname": "1b026b5d4d05",
"type": "filebeat",
"id": "08ebce27-53ef-4801-9b76-aad8e2ebad70",
"version": "7.0.0"
},
"host": {
"name": "1b026b5d4d05"
},
"elasticsearch": {
"gc": {
"threads_total_stop_time_sec": "0.0083760",
"stopping_threads_time_sec": "0.0000702",
"jvm_runtime_sec": "1396138.752"
}
},
"input": {
"type": "log"
},
"message": "2018-06-11T01:53:11.382+0000: 1396138.752: Total time for which application threads were stopped: 0.0083760 seconds, Stopping threads took: 0.0000702 seconds",
"event": {
"dataset": "gc",
"module": "elasticsearch",
"created": "2018-12-07T21:33:18.501Z"
}
},
{
"log": {
"file": {
"path": "/go/src/github.com/elastic/beats/filebeat/module/elasticsearch/gc/test/test.log"
},
"offset": 339
},
"service": {
"name": "elasticsearch"
},
"@timestamp": "2018-06-30T11:35:26.632Z",
"agent": {
"type": "filebeat",
"hostname": "1b026b5d4d05",
"ephemeral_id": "03168a4d-dc31-4ea9-9f39-0ced51aad6a1",
"id": "08ebce27-53ef-4801-9b76-aad8e2ebad70",
"version": "7.0.0"
},
"host": {
"name": "1b026b5d4d05"
},
"elasticsearch": {
"gc": {
"phase": {
"cpu_time": {
"real_sec": "0.04",
"user_sec": "0.12",
"sys_sec": "0.00"
},
"weak_refs_processing_time_sec": "0.0003647",
"name": "CMS Final Remark",
"duration_sec": "0.0457689",
"parallel_rescan_time_sec": "0.0148273",
"class_unload_time_sec": "0.0188407",
"scrub_symbol_table_time_sec": "0.0100207",
"scrub_string_table_time_sec": "0.0005253"
},
"old_gen": {
"used_kb": "277821",
"size_kb": "349568"
},
"heap": {
"used_kb": "391020",
"size_kb": "506816"
},
"jvm_runtime_sec": "224.671",
"young_gen": {
"used_kb": "113198",
"size_kb": "157248"
}
}
},
"input": {
"type": "log"
},
"message": "2018-06-30T16:35:26.632+0500: 224.671: [GC (CMS Final Remark) [YG occupancy: 113198 K (157248 K)]224.671: [Rescan (parallel) , 0.0148273 secs]224.686: [weak refs processing, 0.0003647 secs]224.687: [class unloading, 0.0188407 secs]224.705: [scrub symbol table, 0.0100207 secs]224.715: [scrub string table, 0.0005253 secs][1 CMS-remark: 277821K(349568K)] 391020K(506816K), 0.0457689 secs] [Times: user=0.12 sys=0.00, real=0.04 secs]",
"event": {
"dataset": "gc",
"module": "elasticsearch",
"created": "2018-12-07T21:33:18.501Z"
}
}
]
-------------------- >> begin captured stdout << ---------------------
Using elasticsearch: http://elasticsearch:9200
Testing elasticsearch/gc on /go/src/github.com/elastic/beats/filebeat/tests/system/../../module/elasticsearch/gc/test/test.log

--------------------- >> end captured stdout << ----------------------

Standard Output
Using elasticsearch: http://elasticsearch:9200
Testing elasticsearch/gc on /go/src/github.com/elastic/beats/filebeat/tests/system/../../module/elasticsearch/gc/test/test.log

Metadata

Metadata

Assignees

Labels

FilebeatFilebeatTeam:IntegrationsLabel for the Integrations teamflaky-testUnstable or unreliable test cases.

Type

No type

Fields

No fields configured for issues without a type.

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions