Closed Bug 1591373 Opened 6 years ago Closed 4 years ago

frequent 400 BAD REQUESTS in the GCP balrogworkers

Categories

(Release Engineering :: Release Automation, defect)

Product:
Release Engineering
Component:
Release Automation
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: mtabara, Unassigned)

References

Details

(Whiteboard: [releaseduty])

Attachments

(3 files)

[monorepo] bump no. of attempts in balrogscript's redo
62 bytes, text/x-github-pull-request
Details | Review
[clodops-infra] bump memory in balrogworkers
61 bytes, text/x-github-pull-request
Details | Review
[monorepo] downsize the no of attempts to historical value
62 bytes, text/x-github-pull-request
Details | Review

We started seeing this on central and then on beta too, ever since we switched to GCP balrogworkers in the past two weeks.

See some of these samples on beta here.

Recent changes in Balrog included:

  • add more beefy resources handling uwsgi on server side to avoid getting the 502 gateway errors
  • sleep less between retries (from bug 1579067)
  • increase the number of balrogworkers to 40 (up from 10 which we used to have on AWS)

Given that jitter is not too big and the sleep time dropped significantly, combined with the fact that we have way more workers talking to Balrog all at once, I suspect the number of race conditions (which are normal in a balrog job, hence the generous number of retries that we've always had on these) skyrocketed. We need to understand where the culprit is:
a) we either reduce the number of workers to 25-30 or so
b) we sleep a bit more in between retries in balrogworkers
c) we bump the jitter to help with b)
d) something else?

What problems are they causing? The 400s are expected to some degree with the current architecture of Balrog submissions.

(In reply to bhearsum@mozilla.com (:bhearsum) from comment #1)

What problems are they causing? The 400s are expected to some degree with the current architecture of Balrog submissions.

They are retrying until exhaustion causing the jobs to be red, triggering Sheriffs to rerun and escalate to RelEng.

Met with Ben today to talk about this. Conclusions are as follow:

  1. Hard to get this solution right, rather than empirically, as there are lots of variables in the equiation (level of business of the balrog server at that time of submission, number of workers, number of jobs, etc)
  2. In a given release, we see about 10-12 locales per platform maybe. The sleep time is is computed based on sleeptime, jitter and sleepscale (being capped at 30seconds) for now, and it varies from 10-30 seconds. Within this configuration, among 40 existing GCP workers, we're hitting this in less than 2% of the jobs which isn't that bad. Sure, depends on Balrog server business, but we can make some adjustments right away:

a) we can double the number of attempts. Currently set to 10, we're bumping that to 20.
b) if above doesn't work, we can increase the jitter so that we get them out of sync even more, in the hope of preventing these.
c) worst-case scenario, we can downgrade the number of GCP pods but this is our last resort, for emergencies only.

The long-term fix is to change the way we do the blob upload mechanism in Balrog. Likely we'll see some activity around that in 2020/H1.

On the same page though, Ben thinks we may still have a bug in Balrog so he added more logging server-side to try to catch more data.

For now, we'll proceed with a) and wait to see what's going on.

Sheriffs agreed to help us track all future intermittents against this bug. Thanks again for that!

Assignee: nobody → mtabara

We landed the fix in GCP workers. I asked the Sheriffs to pin the potential new intermittent failures against this bug, going further to better track these issues.

Seems like the fix is working so far on nightlies \o/
Leaving this open until beta6 paves its way to the door, before declaring victoryt and potentially bumping balrogworkers pools.

Not a single balrog failure since we deployed this, that's good.
Naturally, we're going to be greedy now and bump from 40 workers to 60 workers to withhold the future load.
Tracking that in bug 1591994.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
See Also: → 1591994

@mtabara - not sure if it's related:

"we should have another look at balrog workers in GCP - https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&revision=271f87528b864c091e90fee8f4cc8cbcdb36cef9&searchStr=c-Up"
"to clarify my last comment - there’s a lot of blue jobs there, and ones which ended in a -9 which might be OOm"

we are unblocked. Seems intermittent which reminded me of this bug.

Flags: needinfo?(mtabara)

See bug 1594720 for more details. We're seeing different issues than this.

Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Flags: needinfo?(mtabara)
Resolution: --- → FIXED
See Also: → 1594720

If this fails again, we should really look into using https://docs.python.org/3/library/tracemalloc.html to trace those memory allocations.

(In reply to Alexandru Michis [:malexandru] from comment #25)

Recent occurrences:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&searchStr=windows%2C2012%2Cx64%2Cshippable%2Copt%2Cbalrog%2Csubmission%2Cof%2Ccomplete%2Cupdates%2Cbalrog-es-ar-win64-shippable%2Fopt%2Cc-up%28es-ar%29&revision=fdd07df83c87f12725f4b97c80e644fd11673977

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=276949559&repo=mozilla-central&lineNumber=85

Hm, the 400 are expected to some extent. It exhausted all 10 atttempts and then failed because of that. It's different than what we had the last couple of days when the memory allocation was causing the worker to die.

:bhearsum - it's been a while since we had 10 attempts, given that I've reduced the no of workers to 25 as well - so less chances of concurency - is there anything that stands out when glancing at this log?

Flags: needinfo?(mtabara) → needinfo?(bhearsum)

(In reply to Mihai Tabara [:mtabara]⌚️GMT from comment #26)

(In reply to Alexandru Michis [:malexandru] from comment #25)

Recent occurrences:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&searchStr=windows%2C2012%2Cx64%2Cshippable%2Copt%2Cbalrog%2Csubmission%2Cof%2Ccomplete%2Cupdates%2Cbalrog-es-ar-win64-shippable%2Fopt%2Cc-up%28es-ar%29&revision=fdd07df83c87f12725f4b97c80e644fd11673977

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=276949559&repo=mozilla-central&lineNumber=85

Hm, the 400 are expected to some extent. It exhausted all 10 atttempts and then failed because of that. It's different than what we had the last couple of days when the memory allocation was causing the worker to die.

:bhearsum - it's been a while since we had 10 attempts, given that I've reduced the no of workers to 25 as well - so less chances of concurency - is there anything that stands out when glancing at this log?

Looks like the usual to me. The server logs might be more revealing, but I don't have time to go through them at the moment. I'll try to dig into that later this week or next.

Can we reopen this in the meantime?

Flags: needinfo?(mtabara)

(In reply to Alexandru Michis [:malexandru] from comment #28)

Can we reopen this in the meantime?

Sure.

Flags: needinfo?(mtabara)

It'd be good to track these 400 over the next weeks to see where we are. Thanks for raising this!

Status: RESOLVED → REOPENED
Resolution: FIXED → ---

I'm not actively working on this. We're going to change the way we do blob uploads in Balrog in 2020 so likely this bug will be outlived at some point. However, it's still useful to Sheriffs to track how many 400 BAD REQUEST they're still seeing in our infrastructure. For that reason, let's leave this open.

Assignee: mtabara → nobody
Flags: needinfo?(bhearsum)

Number of balrogworkers has been downgraded to 15 so we should stop seeing even these BAD REQUESTs coming in the following weeks/months. The real fix is underway in H1 where we'll likely replace the blob upload gear altogether.

This is mostly fixed now. We've rolled out a new API for balrog releases to nightly, so we should see none of these errors there anymore.

It will ride to beta/release with 83.0, and we should backport to esr78 as well. Once we're using it everywhere, we should crank up the pool size again.

Status: REOPENED → RESOLVED
Closed: 6 years ago → 4 years ago
Resolution: --- → FIXED
Component: Release Automation: Updates → Release Automation
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: