Page MenuHomePhabricator

etcd in codfw burned all latency SLO error budget
Closed, ResolvedPublic

Description

The etcd nodes in codfw burned the error budget set for latency, here's the related SLI metric.

The issue seems started July 18th at around 9:30 UTC, matching:

  • Increased tcp retransmits - metric
  • Packets dropped - metric

Ran ethtool -S eno1 on conf2005 and got the following interesting counters:

rx_discards: 24344
mbuf_lwm_thresh_hit: 24344

Similar values also present on 2004 and 2006.

On SAL the following is registered:

2023-07-18 - production
09:24	<XioNoX>	remove asw-b1-codfw from asw-b-codfw VC - T342076	[production]

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

Mentioned in SAL (#wikimedia-operations) [2023-09-06T13:38:32Z] <akosiaris> sudo ethtool -G eno1 rx 1000 on conf2004 T345738

Surely not related but I noticed that the conf2xxx nodes hold a ton (8/9k) sockets in TIME_WAIT, most of them related to nginx -> etcd local traffic.

I think that it should be safe to enable`tcp_tw_reuse` to improve the situation.

So, ethtool -G eno1 rx 1000 apparently did the trick

image.png (886×807 px, 31 KB)

However, the actual SLI metric hasn't budged much.

Mentioned in SAL (#wikimedia-operations) [2023-09-06T15:38:07Z] <akosiaris> sudo ethtool -G eno1 rx 1000 on conf2005, conf2006 to test out the theory. T345738

We removed switch asw-b1-codfw as it no longer had any servers connected (they were moved to cloudsw1-b1-codfw). The correlation between that event and the jump in TCP retransmissions is stark, but I'm struggling to understand how it would have caused it:

image.png (1,151×387 px, 58 KB)

It's true that the traffic flows between members of the Juniper virtual-chassis is fairly opaque, but the switches in B2 and B7 are aggregating all the other rows. So asw-b1-codfw should in no way have been playing a role in traffic to/from racks B2-B8. @ayounsi is there anything there I might be missing?

In terms of the inbound RX drops on the conf server, that's definitely a host-side thing. Increasing buffers can help to deal with any bursts there, as per the fix to increase RX ring size.

Normally you need to identify what is unable to de-queue the packets from the previous layer fast enough that's causing buffers to fill. Looking at the node_netstat_TcpExt_TCPRcvQDrop metric for conf2005 there doesn't seem to be evidence the TCP buffers are filling up.

It may help to increase the number of cores used for receive-side scaling. I note the system currently has 4 configured (ethtool -L). It has 8 cpu cores, and from what I can tell hyper-threading is not enabled, so the optimal value for that would be 8 (it's also single-socket so NUMA isn't a consideration). I'm far from an expert on this stuff though.

Thanks, we had a quick chat on IRC about that and indeed that's the current conclusion. The extra details your provided (and fix suggestions) are welcome too!

@cmooney @ayounsi thanks a lot! On the host side, I'd try two things (not sure if they could help or not):

  1. Do a simple reboot. The hosts have an uptime of more than a year, and they are running Buster etc.. I would like to rule out the kernel status/version (since we'll likely pick a newer one) from the possible causes.
  2. On every node there are 7/8k sockets in TIME_WAIT at any given time, most of them related to (afaics) local sockets between nginx and etcd. I'd try to enable the net.ipv4.tcp_tw_reuse setting since my understanding, from this guide (I keep re-reading it every time I want to apply this option), is that we'd be in the client use case (even if on the server side), so it would probably help in reducing the lingering TIME WAIT sockets.

Any suggestion/opinion/doubt etc..?

Hi

TL;DR

cadvisor is to blame. Adding @fgiunchedi for his information and a thumbs up on disabling cadvisor on conf2* until we can bump their kernel version.

Long version

I 've been slow drafting this since yesterday.

I think the RX drops is a red herring. I based this on the following reasons:

  1. The drops were on the order of millipackets per second when they occured. Sure, this is due to averaging across time and all, but the order of magnitude is so small that we were probably losing very few packets and thus doubtful they were packets that had something to do with the TCP connections that etcd maintains.
  2. When I bumped the rx buffers of the nic cards on all 3 hosts, the broadcom NIC specific metric, mbuf_lwm_thresh_hit stopped climbing and remained steady. rx_discards, which supposedly contains this broadcomm specific metric stopped increasing too. Per https://www.spinics.net/lists/netdev/msg161734.html that metric is about unwanted multicast frames.
  3. Despite the rx buffer increase, we noticed no difference in the latency quantiles of etcd QGETs (which require quorum across all 3 nodes), minus a 10% decrease in the smallest bucket (le=0.001), which is arguably something we don't care much about (our SLO targets le=0.032)

Now, to provide some more data.

I 've went ahead and filtered through all the TCP metrics those hosts emit. I 've compiled the following dashboard:

https://grafana.wikimedia.org/d/NBywpUzIk/debugging-t345738

What I notice is that suddenly and out of nowhere, all 3 hosts (which btw are in different rows) started:

  1. Sending 1 order of magnitude more DelayedACKs.
  2. Same order of increase in Lost DelayedACKs (probably the remote peer retransmitted a packet)
  3. Same order of increase in duplicate Selective ACKs.

And ALL of this makes 0 sense to me.

I 've also installed mtr-tiny and I 've run reports like so

conf2004:~$ sudo mtr -s 130 -c 100 -w conf2005

HOST: conf2004 Loss% Snt Last Avg Best Wrst StDev
.|-- ae2-2018.cr1-codfw.wikimedia.org 0.0% 100 2.7 2.0 0.3 61.9 7.4
.|-- conf2005.codfw.wmnet 0.0% 100 0.3 2.5 0.2 88.7 12.7

I 've bolded the averages as 2.5 milliseconds intra DC between the 2 rows is suspiciously high. The packet size of 130 bytes is what I see the average packet size being from grafana for those hosts.

Confusingly, I can not reproduce this with either larger packet sizes or mw hosts on the same rows combinations.

And today, I gave up on all the above angles and tried to see what else changed on those hosts on that point in time. And...

akosiaris@conf2004:~$ ls -l /var/lib/dpkg/info/cadvisor.list 
-rw-r--r-- 1 root root 470 Jul 18 09:24 /var/lib/dpkg/info/cadvisor.list

which is right on the minute. And sure enough, after disabling puppet on those hosts and stopping cadvisor

image.png (863×794 px, 29 KB)

The removal of asw-b1-codfw is pure coincidence (which is actually reassuring to me)

This isn't present in conf1* hosts, despite also running cadvisor and the same exact version, presumably because of a different kernel version. conf1* hosts are bullseye and conf2* hosts are buster. 5.10.0-15-amd64 vs 4.19.0-20-amd64

There's a few more actionables here:

  1. Re-evaluate our SLO target for conf hosts etcd service. Despite having exhausted the error budget, we noticed nothing, meaning that we probably were more aggressive than needed latency wise.
  2. Setup monitoring for SLO exhaustion (cueing in @RLazarus, I think there's already something in the works)
  3. Recap that we failed the SLO and failed to notice that we failed the SLO
  4. Probably a blog post?

Hi

TL;DR

cadvisor is to blame. Adding @fgiunchedi for his information and a thumbs up on disabling cadvisor on conf2* until we can bump their kernel version.

I'm ok to disable cadvisor there, though I gotta ask what are the plans for conf2* upgrades and/or reboot ?

Change 955583 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[operations/puppet@production] configcluster: Disable cadvisor in codfw

https://gerrit.wikimedia.org/r/955583

Hi

TL;DR

cadvisor is to blame. Adding @fgiunchedi for his information and a thumbs up on disabling cadvisor on conf2* until we can bump their kernel version.

I'm ok to disable cadvisor there, though I gotta ask what are the plans for conf2* upgrades and/or reboot ?

For upgrades there is T332010: Migrate conf2* hosts to bullseye

Hi

TL;DR

cadvisor is to blame. Adding @fgiunchedi for his information and a thumbs up on disabling cadvisor on conf2* until we can bump their kernel version.

I'm ok to disable cadvisor there, though I gotta ask what are the plans for conf2* upgrades and/or reboot ?

Upgrades are tracked in T332010, so we 'll get them done.
Note that this cluster isn't scheduled for a refresh this FY, so we can't piggyback this on decommissioning those hosts.

Reboots is something we specifically asked to exclude these hosts from as they are disruptive to pybal, which needs to be restarted on all DCs using this cluster to recover.

akosiaris triaged this task as Medium priority.Sep 7 2023, 11:18 AM

Given this isn't urgent and we have multiple ways of dealing with this, I 've re-enabled puppet and cadvisor has been started again. Sure enough, the latency has increased again.

conf2 nodes are on bullseye now and the metrics do look better now, as expected

akosiaris claimed this task.

Resolving per last comment. 2 year old task anyway.

Change #955583 abandoned by Alexandros Kosiaris:

[operations/puppet@production] configcluster: Disable cadvisor in codfw

Reason:

Related task was solved via upgrading the hosts and thus getting rid of the issue.

https://gerrit.wikimedia.org/r/955583