Skip to content

Add post log parser to look for repeated test runs and annotate as in… #8696

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

Open
wants to merge 8 commits into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
31 changes: 29 additions & 2 deletions tests/conftest.py
Original file line number Diff line number Diff line change
Expand Up @@ -315,7 +315,10 @@ def fixture_create_jobs(test_repository, failure_classifications):

def create(jobs):
store_job_data(test_repository, jobs)
return [th_models.Job.objects.get(id=i) for i in range(1, len(jobs) + 1)]
retval = []
for i in range(1, len(jobs) + 1):
retval.append(th_models.Job.objects.get(id=i))
return retval

return create

Expand Down Expand Up @@ -379,6 +382,29 @@ def task_mock(*args, **kwargs):
monkeypatch.setattr(tasks, "parse_logs", task_mock)


@pytest.fixture
def mock_parser(monkeypatch):
from celery import shared_task

from treeherder.log_parser import failureline

@shared_task
def fetch_mock(*args, **kwargs):
file_name = args[0].url.split("/")[-1]
try:
data_path = os.path.join(SAMPLE_DATA_PATH, "logs", file_name)
with open(data_path) as f:
fetch_data = f.read()
except Exception:
return

if not fetch_data:
return
return (json.loads(item.strip("\n")) for item in fetch_data.splitlines())

monkeypatch.setattr(failureline, "fetch_log", fetch_mock)


@pytest.fixture
def taskcluster_notify_mock(monkeypatch):
mock = MagicMock()
Expand Down Expand Up @@ -597,8 +623,9 @@ def failure_classifications(transactional_db):
"expected fail",
"intermittent",
"infra",
"intermittent needs filing",
"new failure not classified",
"autoclassified intermittent",
"intermittent needs bugid",
]:
th_models.FailureClassification(name=name).save()

Expand Down
2 changes: 1 addition & 1 deletion tests/etl/test_classification_loader.py
Original file line number Diff line number Diff line change
Expand Up @@ -539,7 +539,7 @@ def test_new_classification(autoland_push, sample_data, test_two_jobs_tc_metadat
# first is NEW
second_job = Job.objects.get(id=1)
first_job = Job.objects.get(id=2)
assert first_job.failure_classification.name == "intermittent needs filing"
assert first_job.failure_classification.name == "new failure not classified"

# second instance is normal
assert second_job.failure_classification.name == "not classified"
Expand Down
235 changes: 223 additions & 12 deletions tests/log_parser/test_store_failure_lines.py
Original file line number Diff line number Diff line change
Expand Up @@ -5,12 +5,9 @@
from django.conf import settings
from requests.exceptions import HTTPError

from treeherder.log_parser.failureline import (
get_group_results,
store_failure_lines,
write_failure_lines,
)
from treeherder.model.models import FailureLine, Group, GroupStatus, JobLog
from treeherder.log_parser.failureline import get_group_results, write_failure_lines
from treeherder.log_parser.tasks import store_failure_lines
from treeherder.model.models import FailureLine, Group, GroupStatus, Job, JobLog

from ..sampledata import SampleData

Expand Down Expand Up @@ -140,7 +137,7 @@ def test_store_error_summary_500(activate_responses, test_repository, test_job):
assert log_obj.status == JobLog.FAILED


def test_store_error_summary_duplicate(activate_responses, test_repository, test_job):
def test_store_error_summary_duplicate(activate_responses, test_repository, test_job, mock_parser):
log_url = "http://my-log.mozilla.org"
log_obj = JobLog.objects.create(job=test_job, name="errorsummary_json", url=log_url)

Expand Down Expand Up @@ -173,13 +170,18 @@ def test_store_error_summary_group_status(activate_responses, test_repository, t
ok_groups = Group.objects.filter(group_result__status=GroupStatus.OK)
error_groups = Group.objects.filter(group_result__status=GroupStatus.ERROR)

assert ok_groups.count() == 28
assert error_groups.count() == 1
assert ok_groups.count() == 26
assert error_groups.count() == 3
assert log_obj.groups.count() == 29

assert log_obj.groups.all().first().name == "dom/base/test/browser.ini"
assert ok_groups.first().name == "dom/base/test/browser.ini"
assert error_groups.first().name == "toolkit/components/pictureinpicture/tests/browser.ini"
assert (
log_obj.groups.all().order_by("name").first().name == "accessible/tests/browser/browser.ini"
)
assert ok_groups.order_by("name").first().name == "accessible/tests/browser/browser.ini"
assert (
error_groups.order_by("name").first().name
== "browser/components/preferences/tests/browser.ini"
)


def test_group_status_duration(activate_responses, test_repository, test_job):
Expand Down Expand Up @@ -238,3 +240,212 @@ def test_get_group_results_with_colon(activate_responses, test_repository, test_
assert task_groups[
"toolkit/components/extensions/test/xpcshell/xpcshell-e10s.ini:toolkit/components/extensions/test/xpcshell/xpcshell-common-e10s.ini"
]


def mock_full_log_parser(job_logs, mock_parser):
from treeherder.log_parser.tasks import store_failure_lines

try:
# note: I was using parse_logs, but that is less deterministic
for jl in job_logs:
store_failure_lines(jl)
except:
raise


def create_errorsummary_job(base_job, create_jobs, log_filenames):
import copy

job_defs = []
urls = []
counter = 0
for log_filename in log_filenames:
log_path = SampleData().get_log_path(log_filename)
log_url = f"http://my-log.mozilla.org/{log_path}"

with open(log_path) as log_handler:
responses.add(responses.GET, log_url, body=log_handler.read(), status=200)

job_def = copy.deepcopy(base_job)

task_ending = ""
if "_cf" in log_filename:
task_ending = "-cf"

job_def["job"].update(
{
"status": "completed",
"result": "success" if "_pass" in log_filename else "testfailed",
"name": f"{job_def['job']['name']}{task_ending}",
"reference_data_name": job_def["job"]["reference_data_name"].replace(
"a", str(counter)
),
"job_guid": job_def["job"]["job_guid"]
.replace("e", str(counter))
.replace("d", str(counter)),
"start_timestamp": job_def["job"]["start_timestamp"] + 100 + counter,
"taskcluster_task_id": job_def["job"]["taskcluster_task_id"].replace(
"T", str(counter)
),
"taskcluster_retry_id": "0",
}
)
job_defs.append(job_def)
urls.append(log_url)
counter += 1

jobs = create_jobs(job_defs)

index = 0
for job in jobs:
log_obj = JobLog.objects.create(job=job, name="errorsummary_json", url=urls[index])
store_failure_lines(log_obj)
index += 1

return jobs


def verify_classification_id(jobs, job1_fcid, job2_fcid):
j1 = Job.objects.filter(id=jobs[0].id)
j2 = Job.objects.filter(id=jobs[1].id)
assert j1[0].failure_classification.id == job1_fcid
assert j2[0].failure_classification.id == job2_fcid


"""
TODO: write tests for testing intermittents.py handling in the parser.
* not supported yet: test infra/tooling error + 1x green - both green
* test multiple push ids
"""


def test_infra_no_intermittent(activate_responses, hundred_job_blobs, mock_parser, create_jobs):
# test fails, retrigger fails on infra, both unchanged
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_infra_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 1, 1)


def test_infra_intermittent(activate_responses, hundred_job_blobs, mock_parser, create_jobs):
# test passes, retrigger is infra, infra -> unchanged (new feature needed to make intermittent)
log_filenames = [
"mochitest-browser-chrome_infra_errorsummary.log",
"mochitest-browser-chrome_pass_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 8, 1)


def test_multiple_jobs_intermittent(
activate_responses, hundred_job_blobs, mock_parser, create_jobs
):
# two sets of tests fail, both failures should be intermittent
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_2_errorsummary.log",
"mochitest-browser-chrome_pass_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 8, 8)


def test_confirm_failure_no_intermittent(
activate_responses, hundred_job_blobs, mock_parser, create_jobs
):
# test fails, -cf fails on same group, both unchanged
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_cf1_errorsummary.log",
"mochitest-browser-chrome_cf2_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 1, 1)


def test_confirm_failure_partial_intermittent(
activate_responses, hundred_job_blobs, mock_parser, create_jobs
):
# test fails, -cf fails on same group, both unchanged
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_cf1_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 1, 1)


def test_confirm_failure_pass_intermittent(
activate_responses, hundred_job_blobs, mock_parser, create_jobs
):
# test fails, -cf passes, original -> intermittent
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_cf1_pass_errorsummary.log",
"mochitest-browser-chrome_cf2_pass_errorsummary.log",
"mochitest-browser-chrome_cf3_pass_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 8, 1)


def test_retrigger_no_intermittent(activate_responses, hundred_job_blobs, mock_parser, create_jobs):
# test fails, retrigger fails on same group, both unchanged
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 1, 1)


def test_retrigger_intermittent(activate_responses, hundred_job_blobs, mock_parser, create_jobs):
# test fails, retrigger has different failures on same group, both -> intermittent
log_filenames = [
"mochitest-browser-chrome_errorsummary.log",
"mochitest-browser-chrome_2_errorsummary.log",
]
jobs = create_errorsummary_job(hundred_job_blobs[0], create_jobs, log_filenames)
job_logs = JobLog.objects.filter(job_id__in=(j.id for j in jobs))
assert len(jobs) == len(log_filenames)

# this will parse and check for intermittents
mock_full_log_parser(job_logs, mock_parser)
verify_classification_id(jobs, 8, 8)
35 changes: 35 additions & 0 deletions tests/sample_data/logs/mochitest-browser-chrome_2_errorsummary.log
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
{"action": "test_groups", "line": 2, "groups": ["dom/base/test/browser.ini", "browser/components/contextualidentity/test/browser/browser.ini", "browser/base/content/test/tabMediaIndicator/browser.ini", "gfx/tests/browser/browser.ini", "browser/components/downloads/test/browser/browser.ini", "toolkit/components/satchel/test/browser/browser.ini", "toolkit/components/aboutperformance/tests/browser/browser.ini", "toolkit/components/aboutprocesses/tests/browser/browser.ini", "security/manager/ssl/tests/mochitest/browser/browser.ini", "toolkit/components/mozprotocol/tests/browser.ini", "netwerk/test/browser/browser.ini", "browser/base/content/test/siteIdentity/browser.ini", "dom/workers/test/browser.ini", "browser/components/preferences/tests/browser.ini", "browser/base/content/test/about/browser.ini", "browser/base/content/test/popups/browser.ini", "accessible/tests/browser/tree/browser.ini", "toolkit/components/remotepagemanager/tests/browser/browser.ini", "dom/xhr/tests/browser.ini", "dom/security/test/mixedcontentblocker/browser.ini", "browser/components/tests/browser/whats_new_page/browser.ini", "toolkit/content/tests/browser/browser.ini", "dom/broadcastchannel/tests/browser.ini", "caps/tests/mochitest/browser.ini", "browser/components/aboutconfig/test/browser/browser.ini", "browser/components/pocket/test/browser.ini", "accessible/tests/browser/browser.ini", "toolkit/components/pictureinpicture/tests/browser.ini", "dom/ipc/tests/browser.ini", "dom/ipc/tests/JSWindowActor/browser.ini"]}
{"status": "FAIL", "subtest": "Uncaught exception", "group": "browser/base/content/test/popups/browser.ini", "duration": 3141, "action": "test_result", "known_intermittent": [], "test": "browser/base/content/test/popups/browser_fullscreen.js", "message": "undefined - timed out after 50 tries.", "line": 4167, "stack": null, "expected": "PASS"}
{"status": "FAIL", "subtest": "Found an unexpected tab at the end of test run: http://example.com/browser/base/content/test/popups/test-page.html", "group": "browser/base/content/test/popups/browser.ini", "duration": 3141, "action": "test_result", "known_intermittent": [], "test": "browser/base/content/test/popups/browser_fullscreen.js", "message": "", "line": 4172, "stack": null, "expected": "PASS"}
{"status": "FAIL", "subtest": "Test timed out", "group": "browser/base/content/test/popups/browser.ini", "duration": 3141, "action": "test_result", "known_intermittent": [], "test": "browser/base/content/test/popups/browser_videoSelection.js", "message": "", "line": 4269, "stack": null, "expected": "PASS"}
{"status": "FAIL", "subtest": "A promise chain failed to handle a rejection: Video is being cloned visually. - timed out after 50 tries. - stack: (No stack available.)\nRejection date: Thu Oct 08 2020 20:47:46 GMT+0000 (Coordinated Universal Time) - false == true", "group": "browser/base/content/test/popups/browser.ini", "duration": 3141, "action": "test_result", "known_intermittent": [], "test": "browser/base/content/test/popups/browser_videoSelection.js", "message": "JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 265\nStack trace:\nresource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:265\nchrome://mochikit/content/browser-test.js:nextTest:615\nchrome://mochikit/content/browser-test.js:timeoutFn:1195", "line": 4271, "stack": null, "expected": "PASS"}
{"status": "FAIL", "subtest": "Found a tab after previous test timed out: http://example.com/browser/base/content/test/popups/test-video-selection.html", "group": "browser/base/content/test/popups/browser.ini", "duration": 3141, "action": "test_result", "known_intermittent": [], "test": "browser/base/content/test/popups/browser_videoSelection.js", "message": "", "line": 4275, "stack": null, "expected": "PASS"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/base/test/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/components/contextualidentity/test/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/base/content/test/tabMediaIndicator/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "gfx/tests/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/components/downloads/test/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "toolkit/components/satchel/test/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "toolkit/components/aboutperformance/tests/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "toolkit/components/aboutprocesses/tests/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "security/manager/ssl/tests/mochitest/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "toolkit/components/mozprotocol/tests/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "netwerk/test/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/base/content/test/siteIdentity/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/workers/test/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/components/preferences/tests/browser.ini"}
{"status": "OK", "duration": 0, "action": "group_result", "line": 4865, "group": "toolkit/components/pictureinpicture/tests/browser.ini"}
{"status": "ERROR", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/base/content/test/popups/browser.ini"}
{"status": "ERROR", "duration": 3141, "action": "group_result", "line": 4865, "group": "accessible/tests/browser/tree/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "toolkit/components/remotepagemanager/tests/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/xhr/tests/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/security/test/mixedcontentblocker/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "toolkit/content/tests/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/broadcastchannel/tests/browser.ini"}
{"status": "OK", "duration": null, "action": "group_result", "line": 4865, "group": "caps/tests/mochitest/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/components/aboutconfig/test/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/components/pocket/test/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "accessible/tests/browser/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "browser/base/content/test/about/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/ipc/tests/browser.ini"}
{"status": "OK", "duration": 3141, "action": "group_result", "line": 4865, "group": "dom/ipc/tests/JSWindowActor/browser.ini"}
Loading