Isolated build delays on travis-ci.com

Incident Report for Travis CI

Postmortem

We strive to provide a high level of service and stability in our product and some recent events have resulted in us falling short of that goal. We are truly sorry for the disruptions, and we would like to share the details of what happened and how we are going to prevent such disruptions in the future.

Over the past 5 days, we experienced multiple incidents related to our RabbitMQ infrastructure for private repositories. We use a third-party infrastructure provider for RabbitMQ, and our understanding of the exact infrastructure has changed a great deal as a result of these incidents. Prior to these incidents, we believed our RabbitMQ setup was a 2-node cluster running on 2 EC2 instances of the same instance type. What we came to find out was that the EC2 instances were two different sizes, and that the smaller of the two instances (an m1.small) was handling the majority of message routing as well as a stats-gathering process. Part of the resolution of these incidents involved provisioning a new EC2 instance, moving the stats process, and changing the configuration of consumer applications, so we now feel we have identified the necessary steps to provide more stability going forward.

The incident with the longest outage happened on Tuesday, November 18th, with a secondary incident happening a day later on Wednesday, November 19th through the early morning of Thursday, November 20th.

2014-11-18 16:56 UTC - first alert of log messages getting backed up

Once we recevied our first alert about build log message delivery being backed up, we began looking into typical causes. We've experienced issues in the past with the component responsible for processing build log messages, travis-logs. We run multiple processes of travis-logs with JRuby, with each process running multiple threads.

The restart of travis-logs did not appear to have any effect on the growth of undelivered messages, so we then resorted to scaling up the number of processes, thinking that it was best to attempt to catch up with the backlog while looking for the root cause. There was no indication of any problems with either Pusher or our PostgreSQL database, so we began digging more into the possibility of RabbitMQ being the source of the backup. We contacted our RabbitMQ infrastructure provider for assistance.

2014-11-18 17:32 UTC - message publishing and delivery stops

While continuing to investigate, we noticed that all message publishing and delivery in our RabbitMQ cluster came to a halt. Upon looking at our available metrics, we could see that the cluster had not died, but was apparently not reporting any metrics and was performing far below normal levels. The result looked like this:

Once the message publish and delivery resumed, we noticed an increase in throughput, but were still falling behind. The graphs available to us showing the CPU and Memory load of each node showed that the primary node was under significantly more stress than the secondary, which led us to consider a rolling restart in an attempt to redistribute the client connections.

2014-11-18 19:16 UTC - restarting the RabbitMQ cluster

We began restarting each RabbitMQ node via web-based administrative tools. The first node we restarted came back up without any apparent problems, so we decided to continue restarting the remaining node. After the second node restarted, we began experiencing issues signing into the RabbitMQ management UI. At this point, the RabbitMQ cluster appeared to be unusable.

2014-11-18 19:38 UTC - recovering the RabbitMQ cluster

Since restarting the RabbitMQ cluster ourselves and effectively disabling it, we fortunately were able to engage with our RabbitMQ infrastructure provider via chat. At this point several important factors became clear, not least that the gap in publish/delivery had been the result of CPU throttling, and that the RabbitMQ cluster had become unusable because the secondary node had decided to form its own cluster after experiencing a temporary issue with DNS. At this point we knew that the m1.small instance would have to be re-provisioned, but were unsure of how long it would take and did not want to prolong the outage unnecessarily. We decided then that the new instance would be added later in the week during a planned maintenance.

2014-11-18 20:12 UTC - resume producer and consumer components

Once the RabbitMQ cluster was back online, we began restarting all of the producer and consumer components including travis-logs, travis-hub, travis-api, and our entire worker fleet. All of the builds that had been interrupted during the outage were restarted, and we confirmed that builds were running again by 20:28 UTC. Unfortunately, all of the existing build log messages were lost.

2014-11-19 21:51 UTC - received alert of build logs getting backed up

One day later, we received an alert about build log messages getting backed up, which looked very similar to the incident the previous day. Upon getting in contact with our RabbitMQ infrastructure provider, we followed their recommendation to mitigate the backup by increasing prefetch counts in our message consumers, most notably travis-logs. Before our configuration change could be deployed, a change on the infrastructure side to move an expensive stats collection process from the smaller to the larger instance resulted in the queue draining prior to the prefetch change having any effect.

At this point we decided that the upgrade of the smaller EC2 instance from an m1.small to an m3.medium could not wait until later in the week, and would be done right away. This upgrade went forward, after which we restarted all processes that had been connected to the smaller instance. We noticed a delay in message delivery while the newly provisioned instance began handling traffic, but no messages were lost.

How we're going to prevent it in the future

Having upgraded the EC2 instances to solve the immediate load issues, we turned our attention to all other aspects of our RabbitMQ configuration, including how all of our producer and consumer applications interact with the cluster. Among the items we're planning to address in the near future are:

  • Upgrading the RabbitMQ cluster to a much more recent version with support for ha policies to help with preventing message loss
  • Updating all client libraries to latest stable versions to ensure automatic reconnect is supported across the board
  • Adjusting the QOS settings for each client to be better aligned with their unique workloads

We look forward to rolling out these changes, and will be communicating the news via the blog. Again, we are truly sorry for failing to provide the level of stability and quality we expect from ourselves, and thank you for your patience.

Posted Nov 21, 2014 - 19:47 UTC

Resolved

Everything operational, we've worked through the backlog.
Posted Nov 20, 2014 - 14:31 UTC

Update

We're still working through the backlog of previously stalled builds.
Posted Nov 20, 2014 - 07:11 UTC

Monitoring

During our emergency RabbitMQ cluster update over the last 24 hours, some jobs were stuck in a queued state which has held up other jobs from starting and completing.

We have identified the stuck jobs and restarted them accordingly.

We are monitoring the processing of these jobs and will update this ticket once the backlog is cleared.

We are sorry for this issue and will be improving our monitoring and alerting to identify jobs which are queued for extended periods of time.
Posted Nov 20, 2014 - 04:16 UTC