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.

Sign up for GitHub

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

Jump to bottom

Filebeat Module Tests are Flaky #9502

Closed
andrewvc opened this issue Dec 12, 2018 · 2 comments
Closed

Filebeat Module Tests are Flaky #9502

andrewvc opened this issue Dec 12, 2018 · 2 comments
Assignees
@ruflin
Labels
Filebeat Filebeat flaky-test Unstable or unreliable test cases. Team:Integrations Label for the Integrations team

Comments

@andrewvc
Copy link
Contributor

andrewvc commented Dec 12, 2018 •
edited
Loading

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
@andrewvc andrewvc added Filebeat Filebeat flaky-test Unstable or unreliable test cases. labels Dec 12, 2018
andrewvc added a commit to andrewvc/beats that referenced this issue Dec 12, 2018
@andrewvc
Mutes flaky filebeat module tests
7584d5f 
This is a temporary solution to elastic#9502

This mutes those tests temporarily.
@andrewvc andrewvc mentioned this issue Dec 12, 2018
Closed
@ruflin ruflin self-assigned this Dec 12, 2018
@ruflin ruflin added the Team:Integrations Label for the Integrations team label Dec 12, 2018
@elasticmachine
Copy link
Collaborator

Pinging @elastic/infrastructure

@ruflin
Copy link
Member

ruflin commented Dec 14, 2018

Closing this one as I think we figure out that this is not actually a flaky test but golden files that need update.

@ruflin ruflin closed this as completed Dec 14, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@ruflin ruflin

Labels
Filebeat Filebeat flaky-test Unstable or unreliable test cases. Team:Integrations Label for the Integrations team
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@andrewvc @ruflin @elasticmachine