GNUTLS_E_AGAIN is treated as fatal, large syncs abort part-way through #45

Hi,

I've been moving a fairly large tree around with csync2 and ran into something that took me a while to pin down, so I figured I'd write it up properly.

Setup is three Debian trixie nodes, package 2.0-42-g83b3644 (csync2 2.1-0rc1), GnuTLS build. Pushing ~31 GB / 56k files to two peers, csync2 never finished in one go. It would run for a few minutes, die with

Read-error while receiving data.      # on the receiving node
Write-error while sending data.       # on the sending node

and then pick up where it left off on the next run. Took seven runs to converge.
Nothing in the logs suggested why.

What made me stop blaming the network is that the abort point is completely deterministic: 8.0 GB, then 15.4 GB, then 22.9 GB transferred, same numbers on two different peers, and identical again when I rebuilt the package from source.
A flaky link doesn't do that.

So I patched READ() and WRITE() in conn.c to print what GnuTLS actually returns before csync2 gives up, and it's this, on both ends:

sender:   rc=-28 (Resource temporarily unavailable, try again.) count=512
receiver: rc=-28 (Resource temporarily unavailable, try again.) fatal=0 count=512

-28 is GNUTLS_E_AGAIN, and gnutls_error_is_fatal() returns 0 for it. The manual says to just call the function again. csync2 instead passes the negative return up the stack, where conn_read() turns it into a short read and csync_recv_file() hits csync_fatal(), and on the other side csync_send_file() sees rc != chunk and does the same. A whole multi-gigabyte transfer dies on something GnuTLS considers a non-event.

One thing worth mentioning because it cost me a run: I first patched only the sending side, assuming the short write was the problem. That changed absolutely nothing ; same seven runs, same thresholds ; because the receive path then aborts on the identical condition. Both need fixing or neither does.

With both patched, the same 31.66 GB to two peers goes through in a single run, 1938 s, no aborts. I checked the result each time by comparing an md5 of the whole tree on all three nodes; they match.

Patch below, against master:

--- a/conn.c
+++ b/conn.c
@@ -471,7 +471,13 @@
 {
 #ifdef HAVE_LIBGNUTLS
 	if (csync_conn_usessl)
-		return gnutls_record_recv(conn_tls_session, buf, count);
+	{
+		ssize_t rc;
+		do {
+			rc = gnutls_record_recv(conn_tls_session, buf, count);
+		} while (rc == GNUTLS_E_AGAIN || rc == GNUTLS_E_INTERRUPTED);
+		return (int)rc;
+	}
 	else
 #endif
 		return read(conn_fd_in, buf, count);
@@ -482,8 +488,21 @@
 	static int n, total;
 
 #ifdef HAVE_LIBGNUTLS
-	if (csync_conn_usessl)
-		return gnutls_record_send(conn_tls_session, buf, count);
+	if (csync_conn_usessl) {
+		size_t sent = 0;
+		while (sent < count) {
+			ssize_t rc = gnutls_record_send(conn_tls_session,
+					((const char *)buf) + sent, count - sent);
+			if (rc == GNUTLS_E_AGAIN || rc == GNUTLS_E_INTERRUPTED)
+				continue;
+			if (rc < 0)
+				return sent ? (int)sent : (int)rc;
+			if (rc == 0)
+				break;
+			sent += (size_t)rc;
+		}
+		return (int)sent;
+	}
 	else
 #endif
 	{

The send loop only advances the offset after a successful send, so a retry calls gnutls_record_send() with the same pointer and length, which is what the manual asks for. The socket is blocking (nothing sets O_NONBLOCK on conn_fd_in/out), so the retry can't spin ; the next call blocks in the underlying read/write. The non-TLS branch of WRITE() already loops over partial writes and retries EINTR, so this just makes the TLS branch behave the same.

I haven't worked out why GNUTLS_E_AGAIN shows up at that point on a blocking socket. The number of records at the threshold is suspiciously close to 2^24, which would fit a TLS 1.3 key update, but I didn't confirm it and stopped digging once the retry made the problem go away. Either way the condition is non-fatal by GnuTLS's own definition, so retrying seems right regardless of
where it comes from.

Separate thing, happy to open another issue: bumping the 512-byte network chunks in rsync.c to 16 KiB (max TLS record payload) took the same sync from 1938 seconds to 979 seconds. It does depend on the patch above though ; go above the TLS record size without it and gnutls_record_send() returns a short count on the first file, which csync2 currently treats as an error.

Let me know if you want me to test anything else, I still have the setup.