Summary
CI / CD pipeline executions slowed down or timed out because of the high latency of Redis calls from the log service.
Mitigation
- Engaged Redis support
- Increased shards for log service
- Monitored primary shard until CPU usage returned to the expected range
Detailed Timeline(PST)
Time
Event
Notes
8:42 AM
Firehydrant triggered for CI pipeline performance degradation
8:45 AM
Checked Redis memory - it was under the limit
9:05 AM
Figured out that the stream write calls are taking a very long time hence resulting in longer execution times
9:25 AM
Created a P0 with Redis Support
9:50 AM
Increase log-service memory
Since writes were taking longer, the API payloads were still present in log-service increasing the memory usage
10:30 AM
Redis support joined the call Requested shard logs to understand what’s causing the high latency for Redis operations
Explained the chain of events including Redis memory increase from last week.
10:51 AM
Deployed a change to decrease the number of lines in a log stream
Created a temporary fix to decrease the size per stream
11:15 AM
Discovered 100% CPU utilization on Redis shard Performed failover in an attempt to decrease the CPU utilization - did not help
CPU was at 100% since Friday (including the weekend when the load is low)
12PM - 1:30 PM
Gradually increased the number of shards Received logs for 30 second time window for the hot shard (requested at 10:30 AM)
Saw the keys getting distributed evenly across shards but the CPU utilization of the host shard did not come down Hot shard - 100%, Other shards - 30-40% Saw some CRDT operation logs in the shard logs
2:30 PM
Redis team still investigating the issue. Requested for all shard logs and CRDT sync logs.
3:34 PM
Received logs for 30 second time window for all shards
4:01 PM
Redis team pointed out that even though the keys were distributed evenly, the hot shard was consuming more than twice the memory of the newly provisioned shards
Harness team pointed out that the replication was out of sync and there were a lot of CRDT.MERGE logs in the hot shard logs which were missing in the other shard logs
4:08 PM
failover and primary got in sync
4:12 PM
CPU utilization started dropping along with the high memory usage on the hot shard
Incident was marked as resolved
RCA
Why were the pipelines running slow?
The current Redis shard was not able to handle the log streaming load and its CPU was running at 100% and causing higher latency.
Why was the Redis shard CPU running at 100%?
Observations based on the call with the Redis support team
- On 09/29, We noticed the Redis instance was running close to capacity. CloudOps team increased the size of the Redis instance to accommodate for increased load. Unfortunately, the team failed to make corresponding changes in the secondary cluster.
- As per log-service DB alerts in Redis, the sync was failing since 9/29 and did not recover until Monday 10/02 (OOM and connection errors)
- We suspect the sync process might be in a bad state resulting in keeping the CPU at 100% during the weekend too. We are awaiting a detailed RCA from Redis support.
Follow up actions
- Updated the memory of failover to match with primary
- Increased the number of shards
- Working on enhancing monitoring and alerts around latency spikes