Uncovering a 24-year-old bug in the Linux Kernel – Skroutz Engineering

Your browser is quite old! Why not upgrade to a different browser to better enjoy this site?

As part of our standard toolkit, we provide each developer at Skroutz<br>with a writable database snapshot against which she can develop. These<br>snapshots are updated daily through a pipeline that involves taking an<br>LVM snapshot of production data, anonymizing the dataset by stripping<br>all personal data, and transferring it via rsync to the development<br>database servers. The development servers in turn use ZFS snapshots to<br>expose a copy-on-write snapshot to each developer, with<br>self-service tools allowing rollback or upgrades to newer snapshots.

We use the same pipeline to expose MariaDB and MongoDB data, with a<br>full dataset size of 600GB and 200GB respectively, and a slightly<br>modified pipeline for Elasticsearch. While on-disk data changes<br>significantly for all data sources, rsync still saves significant time<br>by transferring roughly 1/3 of the full data set every night. This<br>setup has worked rather well for the better part of a decade and has<br>managed to scale from 15 developers to 150. However, as with most<br>systems, it has had its fair share of maintenance and has given us<br>some interesting moments.

One of the most interesting issues we encountered led to the discovery<br>of a fairly old bug in the Linux kernel TCP implementation: every now<br>and then, an rsync transfer from a source server would hang<br>indefinitely for no apparent reason, as — apart from the stuck transfer —<br>everything else seemed to be in order. What’s more, for reasons that became<br>apparent later, the issue could not be reproduced at will, although<br>some actions (e.g. adding an rsync-level rate limit) seemed to make<br>the issue less frequent, with frequency ranging from once or twice per<br>week to once every three months.

As is not unusual in these cases, we had more urgent systems and issues to<br>attend to, so we labeled this a “race condition in rsync” that we<br>should definitely look into at some point, and worked around it by<br>throttling the rsync transfers.

Until it started biting us every single day.

rsync as a pipeline

While not strictly necessary, knowing how rsync works internally will help<br>understand the analysis that follows. The rsync site contains a thorough<br>description of rsync’s internal architecture, so I’ll try to<br>summarize the most important points here:

rsync starts off as a single process on the client and a single<br>process on the server, communicating via a socket pair. When using<br>the rsync daemon, as in our case, communication is done over a<br>plain TCP connection

Based on the direction of sync, after the initial handshake is<br>over, each end assumes a role, either that of the sender, or<br>that of the receiver. In our case the client is the receiver,<br>and the server is the sender.

The receiver forks an additional process called the generator,<br>sharing the socket with the receiver process. The generator<br>figures out what it needs to ask from the sender, and the<br>sender subsequently sends the data to the receiver. What we<br>essentially have after this step is a pipeline, generator →<br>sender → receiver, where the arrows are the two directions of<br>the same TCP connection. While there is some signaling involved,<br>the pipeline operates in a blocking fashion and relies on OS<br>buffers and TCP receive windows to apply backpressure.

A ghost in the network?

Our first reaction when we encountered the issue was to suspect the<br>network for errors, which was a reasonable thing to do since we had<br>recently upgraded our servers and switches. After eliminating the<br>usual suspects (NIC firmware bugs involving TSO/GSO/GRO/VLAN<br>offloading, excessive packet drops or CRC errors at the switches etc),<br>we came to the conclusion that everything was normal and something<br>else had to be going on.

Attaching the hung processes using strace and gdb told us little: the<br>generator was hung on send() and the sender and receiver were hung<br>on recv(), yet no data was moving. However, turning to the kernel on<br>both systems revealed something interesting! On the client the rsync<br>socket shared between the generator and the receiver processes was<br>in the following state:

$ ss -mito dst :873<br>State Recv-Q Send-Q Local Address:Port Peer Address:Port<br>ESTAB 0 392827 ❶ 2001:db8:2a::3:38022 2001:db8:2a::18:rsync timer:(persist,1min56sec,0)<br>skmem:(r0,rb4194304,t0,tb530944,f3733,w401771,o0,bl0,d757) ts sack cubic wscale:7,7 rto:204 backoff:15 rtt:2.06/0.541 ato:40 mss:1428 cwnd:10 ssthresh:46 bytes_acked:22924107 bytes_received:100439119971 segs_out:7191833 segs_in:70503044 data_segs_out:16161 data_segs_in:70502223 send 55.5Mbps lastsnd:16281856 lastrcv:14261988 lastack:3164 pacing_rate 133.1Mbps retrans:0/11 rcv_rtt:20 rcv_space:2107888 notsent:392827 minrtt:0.189

while on the server, the socket state was the following:

$ ss -mito src :873<br>State Recv-Q Send-Q Local Address:Port Peer Address:Port<br>ESTAB 0 0 2001:db8:2a::18:rsync...