Closed Bug 1297759 Opened 10 years ago Closed 10 years ago

Something seems wrong with amqp + tc again

Categories

(Taskcluster :: Operations and Service Requests, task)

Product:
Taskcluster
Component:
Operations and Service Requests
Type:
task
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: bstack, Assigned: bstack)

References

(
URL
)

Details

Today at around Aug. 24, 2016, 5:19:38 p.m. UTC, the taskcluster team received alerts from sentry that amqplib was yelling about connections being dropped in multiple services, etc. This makes taskcluster quite sad. This bug is a tracking bug to see 1) If we can stand everything back up quickly. 2) Why this has happened again today after last night and to see if we can prevent it from occuring again tomorrow. Examples: https://app.getsentry.com/taskcluster/tc-treeherder/issues/152821803/ https://app.getsentry.com/taskcluster/taskcluster-index/issues/152822130/
I've seen this on pulse_actions as well.
It is a slight possibility that this is a larger problem with ec2 hosted services. We have been seeing errors out of heroku as well which is hosted in us-east I believe and looking at some of the cloudamqp IP addresses, they bare resemblance to IPs AWS has.
Yesterday, bug 1297547 comment 1: According to mcote, our CloudAMQP server is running at orange-antelope.rmq.cloudamqp.com. This resolves as: orange-antelope.rmq.cloudamqp.com. 28 IN CNAME ec2-54-215-254-97.us-west-1.compute.amazonaws.com. ec2-54-215-254-97.us-west-1.compute.amazonaws.com. 3568 IN A 54.215.254.97 Today: orange-antelope.rmq.cloudamqp.com is an alias for ec2-54-183-180-191.us-west-1.compute.amazonaws.com. ec2-54-183-180-191.us-west-1.compute.amazonaws.com has address 54.183.180.191 However, pulse.mozilla.com points to three not-that addresses: pulse.mozilla.org has address 54.215.223.66 pulse.mozilla.org has address 54.215.253.142 pulse.mozilla.org has address 54.215.254.97
See Also: → 1297547
So it looks like anything that connects to pulse is crashing with timeouts. Even TC services you might not suspect, such as AWS provisioner, connect on startup, and are thus failing (mostly with 503's from Heroku)
Most trees have been closed for a while now. I just closed try also so we stop giving people false hope.
I'm going to chain CNAMEs, so pulse.mozilla.org -> orange-antelope.rmq.cloudamqp.com
dns change is in; propagating now
We've restarted a few services and they seem to be happy now with the new dns change in. We're running around to the rest of the services now.
Sorry, C-C was closed before due to bustage, so I pushed a fix and wasn't aware of the general closure. Feel free to cancel the jobs. Sorry again.
I filed bug 1297560 to retry initial connection establishment (PRs already pending). This way we ensure that randomized DNS results will have a shot, even if bad instances aren't removed from DNS records.
See Also: → 1297560
it appears one of our services, taskcluster-treeherder, is still having issues connecting. We attempt to connect a pulse listener using a durable queue and it hangs. When this happened yesterday the workaround at the time was to use a new queue, but unfortunately doing so will mean that any messages that were in that old queue are now lost. Perhaps that queue is not collecting messages anyways if something is hosed, but when attempting to get into pulse guardian, I get a heroku application error.
2:44 PM <nthomas> suprised no-one noticed the lack of buildbot builds on trees <snip> 2:47 PM <nthomas> currently we can't send messages to pulse (firewall rule), so finishing jobs won't end up ingested into treeherder Reclosed all trees.
15:12:16 <arr> the response we got from cloudamqp said that we have 10K connections to pulse and that it might cause memory exhaustion issues. They wanted to know if that's a normal number of connections. 15:12:51 <arr> do you typically make a ton of connections to pulse? 15:13:16 <jonasfj> yes
So the deal is TC workers each establish 2 persistent connections to Pulse (1 to monitor for task cancels, the other for cache purges). We run thousands of workers and our CloudAMQP plan allows 10k active connections. So... What's confusing to me is we've been running thousands of TC workers for weeks without issue. Something must have changed, whether it be us reaching a tipping point with TC worker count, increased load on Pulse, or something on CloudAMQP's end. Should be a fun post mortem.
We are killing off all existing workers and will be deploying a new ami that will only create one pulse listener for now (so the caches can still be purged by sheriffs). We are working to minimize connections in the future by: 1. not worrying about listening for cancellation events from pulse. Reclaim of canceled task should fail and the worker should abort running the task. 2. Change from a pulse driven purge cache model to a polling model (bstack working on that to see how feasible) 3. If #2 is not feasible, we will re-enable cancellations by combining both listeners into one once some more testing is done.
Ok, some of the higher capacity worker types have been updated with a new ami that will not listen for cancel events: Old: pv: us-east-1: ami-dba1c5cc us-west-1: ami-a45e1cc4 us-west-2: ami-c21fcaa2 hvm: us-east-1: ami-557c1c42 us-west-1: ami-97e1a3f7 us-west-2: ami-8729fde7 hvm (android-api-15, dbg-linux32) us-east-1: ami-0ea1c519 us-west-1: ami-f85c1e98 us-west-2: ami-dd1fcabd new: --> hvm-builder: AMIs were created: us-east-1: ami-8f610298 us-west-1: ami-800f42e0 us-west-2: ami-31865151 --> pv-builder: AMIs were created: us-east-1: ami-e76300f0 us-west-1: ami-830f42e3 us-west-2: ami-54805734
I got access to the cloudamqp dashboard and looked at the server metrics for the last 14 days. We've been maxing out memory on 2 of the 3 nodes for the 14 days. I suppose rabbitmq sort of fell over after running that hard for that long. The third node usually was ok. so this is a step towards answering the question "if this was a memory exhaustion issue, and we've been running at this capacity for a while, why the problem now?"
Additionally, memory usage did not seem to be egregiously high during both outages today. I've emailed support about this (both that memory usage has been high for at least a couple weeks with no problems, and that it was relatively low today). However, connection levels were high today, even if memory usage stayed low. So maybe the connection load is affecting the cluster in some way other than RAM (load balancer or whatever sits in front of the RabbitMQ app itself, maybe?).
Severity: normal → blocker
Trees are open.
Severity: blocker → normal
I think this incident is over, so I'm closing this. Any followup work can be done in a separate ticket.
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
jgriffin pointed out today that, while it's hard to tell exactly from the graphs, the nodes may have run out of swap space. That might have been the real culprit.
Adding postmortem doc as the URL field.
URL: https://docs.google.com/document/d/1l...
Component: Operations → Operations and Service Requests
You need to log in before you can comment on or make changes to this bug.