1672869 - Mda jobs thrown as exceptions - Claim expired

Status: RESOLVED FIXED

(Core :: Web Audio, defect)

Description

[Natalia Csoregi [:nataliaCs]]

Many mda exceptions started appearing, which have no logs available:
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2C18.04%2Cx64%2Ctsan%2Copt%2Cmochitests%2Ctest-linux1804-64-tsan%2Fopt-mochitest-media-e10s%2Cmda2&tochange=dafa26b89edacc8d9fb9eade704d7124ba5239cf&fromchange=f2c121c81601b91d45446ee27627ef75555cf57b&group_state=expanded

Task example:
https://firefox-ci-tc.services.mozilla.com/tasks/H5qo8FCXQXC8yBSXYaly7w

It seems like a big number of retries before the test actually runs successfully.

Comment 1

[Intermittent Failures Robot]

43 failures in 865 pushes (0.05 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 41
• mozilla-central: 2

Platform breakdown:

• linux1804-64-tsan: 43

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1672869&startday=2020-10-22&endday=2020-10-22&tree=all

Comment 2

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Started when bug 1648192 added the mda tasks to Linux tsan. The failures are for the test chunk running dom/media/webaudio/test/mochitest.ini and only the tests from that test manifest in the task.

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Paul, Christian, please coordinate how this shall be resolved.

Comment 4

[Christian Holler (:decoder)]

I've seen this too and I am clueless as to why this might happen. Once the tests finish, they finish very quickly with a runtime of only 8 or 9 minutes.

Could this be related to the fact, that a different machine type (xlarge) is requested here with different spot price properties? Might be useful to loop someone in that works on TC. Without any kind of logs, it is going to be hard to figure this out.

Comment 5

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

(In reply to Christian Holler (:decoder) from comment #4)

I've seen this too and I am clueless as to why this might happen. Once the tests finish, they finish very quickly with a runtime of only 8 or 9 minutes.

Could this be related to the fact, that a different machine type (xlarge) is requested here with different spot price properties? Might be useful to loop someone in that works on TC. Without any kind of logs, it is going to be hard to figure this out.

Brian, can you assist Christian? Thanks in advance.

Comment 6

[Brian Stack [:bstack]]

Yeah happy to help. Are only the Mda jobs experiencing this? I've found the worker logs for one of these instances and the machine restarted in the middle of a task without saying why. In our experience this is usually do to OOM or some kernel panic, etc.

My intuition is that if this is only affecting one test type and not a lot of other tasks that happen on these workers it might be that the test is leaking memory or something along those lines? If sheriffs ping me right after the next one of these maybe we can get to the instance in aws before aws forgets about it.

Is there an in-tree reporting mechanism that is tracking how much memory these tasks use?

Comment 7

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Attachment: Bug 1672869 - disable dom/media/webaudio/test/mochitest.ini for ThreadSanitizer because new task fails very frequently. DONTBUILD

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/f82597b1e299
disable dom/media/webaudio/test/mochitest.ini for ThreadSanitizer because new task fails very frequently. DONTBUILD

Comment 9

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/f82597b1e299

Comment 10

[Christian Holler (:decoder)]

Normally I would also have guessed OOM (and I guess we could rule this out by providing an even larger machine, do we have anything larger than xlarge in TC?).

What is confusing to me is: When these jobs finish normally, they only take 8-9 minutes. Normally when tests put a lot of OOM stress on the machine so they sometimes fail, they usually take really long, even if they succeed (because the machine gets delayed from swapping and general bad test performance). This is not the case here. I've also run the tests locally with TSan and couldn't see increased memory usage beyond what we would usually expect from TSan, but I can try to do these again, maybe they happen intermittently?

Comment 11

[Intermittent Failures Robot]

56 failures in 4230 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #15 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 50
• mozilla-central: 4
• try: 2

Platform breakdown:

• linux1804-64-tsan: 56

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1672869&startday=2020-10-19&endday=2020-10-25&tree=all

Comment 12

[Paul Adenot (:padenot)]

(In reply to Brian Stack [:bstack] from comment #6)

Yeah happy to help. Are only the Mda jobs experiencing this? I've found the worker logs for one of these instances and the machine restarted in the middle of a task without saying why. In our experience this is usually do to OOM or some kernel panic, etc.

Please attach the logs here, this links to a login page (or otherwise provide instructions on how to get them). OOM sounds plausible, and we might well be able to modify the test to make this more reliable. Thanks!

Comment 13

[Pete Moore [:pmoore][:pete]]

Perhaps this could also be a worker configuration issue, for example if two workers are configured to run on a single worker, perhaps one is rebooting the machine while the other one is running.

Claim-expired is a resolution that the queue assigns to a task when the worker goes AWOL, when it has failed to reclaim the task within 20 minutes, which it should do if it is actively working on a task. Since logs are streamed during execution, and only uploaded on completion, a worker that "disappears" unexpectedly will leave no trace of logs unfortunately, unless the livelogs are captured as the task happens. If the claim-expired is reasonably repeatable, it may be worth tailing the live logs in a console session while the task runs, in order that they can be captured despite the claim-expired failure. However, even if the worker goes offline, it may be that the worker still retains the task logs, assuming it doesn't terminate, so it may be possible for us to retrieve them for a post mortem.

Note this could also be a worker bug, or a misconfiguration of docker on the worker. Normally for docker-worker tasks, it is difficult for the task to do something evil like reboot the machine mid-task, since it should only be able to affect the docker container the task is running in, not the host environment.

Comment 14

[Brian Stack [:bstack]]

This is not the case here. I've also run the tests locally with TSan and couldn't see increased memory usage beyond what we would usually expect from TSan, but I can try to do these again, maybe they happen intermittently?

Yeah that is definitely confusing. I'm not sure how often this is happening? Is it some constant percentage of these tasks or 100% of them, etc.

Please attach the logs here, this links to a login page (or otherwise provide instructions on how to get them). OOM sounds plausible, and we might well be able to modify the test to make this more reliable. Thanks!

Ah, there's nothing really to see there. The logs just showed normal docker-worker logs followed by the init process of the machine starting again with nothing in between. Shouldn't have even linked really. They're no longer indexed in the web service we use there but I can go get them out of s3 if you'd like to see them.

If the claim-expired is reasonably repeatable, it may be worth tailing the live logs in a console session while the task runs, in order that they can be captured despite the claim-expired failure.

We tried that on Friday a bit and couldn't get it to reproduce at that time. We can try that again today/tomorrow/etc. It might be the best next step forward. Tailing a handful of tasks at a time for a few hours should result in a hit?

Comment 15

[Paul Adenot (:padenot)]

If we can determine whether this happens during a particular test, it can be useful. The media test suite does regression tests and regular tests where it allocates a lot to try to put Firefox into an OOM or quasi-OOM situation that wasn't handled previously, and to check that it's now gracefully handled, but sometimes this cause weird issues.

Comment 16

[Christian Holler (:decoder)]

Attachment: Bug 1672869 - Disable WebAudio OOM test for sanitizers. r?padenot

Comment 17

[Christian Holler (:decoder)]

I found the particular test that causes this (it causes a 12 GB memory rss spike on my local machine) and it looks like that was the main problem:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=df288d9eb2f1a55efd27e271ac1e69e6628c82cc

I've decided to disable this test not just on TSan but also on ASan. Even though it is not failing on ASan right now, such huge allocations can cause large delays with any of the sanitizers an make the test susceptible to intermittents. There is I guess little use for this test on ASan anyway.

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/8ce94732d1ef
Disable WebAudio OOM test for sanitizers. r=padenot

Comment 19

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/8ce94732d1ef

Comment 20

[BugBot [:suhaib / :marco/ :calixte]]

The severity field is not set for this bug.
:padenot, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 21

[Paul Adenot (:padenot)]

Christian, do you think we can backout the first patch in this bug and then we can close this? The second patch should be enough, and I'd rather have TSAN coverage here.

Comment 22

[Christian Holler (:decoder)]

Unless I missed something, the second patch already reverted the first patch?

Comment 23

[Paul Adenot (:padenot)]

Ah brilliant, missed this, thanks. I think we can close this then. Thanks!